This commit is contained in:
2025-10-10 07:13:36 -07:00
commit 95c66c0a8a
1023 changed files with 78353 additions and 0 deletions
+26
View File
@@ -0,0 +1,26 @@
package logger
import (
"sync/atomic"
"github.com/perfect-panel/ppanel-server/pkg/color"
)
// WithColor is a helper function to add color to a string, only in plain encoding.
func WithColor(text string, colour color.Color) string {
if atomic.LoadUint32(&encoding) == plainEncodingType {
return color.WithColor(text, colour)
}
return text
}
// WithColorPadding is a helper function to add color to a string with leading and trailing spaces,
// only in plain encoding.
func WithColorPadding(text string, colour color.Color) string {
if atomic.LoadUint32(&encoding) == plainEncodingType {
return color.WithColorPadding(text, colour)
}
return text
}
+33
View File
@@ -0,0 +1,33 @@
package logger
import (
"sync/atomic"
"testing"
"github.com/perfect-panel/ppanel-server/pkg/color"
"github.com/stretchr/testify/assert"
)
func TestWithColor(t *testing.T) {
old := atomic.SwapUint32(&encoding, plainEncodingType)
defer atomic.StoreUint32(&encoding, old)
output := WithColor("hello", color.BgBlue)
assert.Equal(t, "hello", output)
atomic.StoreUint32(&encoding, jsonEncodingType)
output = WithColor("hello", color.BgBlue)
assert.Equal(t, "hello", output)
}
func TestWithColorPadding(t *testing.T) {
old := atomic.SwapUint32(&encoding, plainEncodingType)
defer atomic.StoreUint32(&encoding, old)
output := WithColorPadding("hello", color.BgBlue)
assert.Equal(t, " hello ", output)
atomic.StoreUint32(&encoding, jsonEncodingType)
output = WithColorPadding("hello", color.BgBlue)
assert.Equal(t, "hello", output)
}
+47
View File
@@ -0,0 +1,47 @@
package logger
// A LogConf is a logging config.
type LogConf struct {
// ServiceName represents the service name.
ServiceName string `yaml:"ServiceName" default:"PPanel"`
// Mode represents the logging mode, default is `console`.
// console: log to console.
// file: log to file.
// volume: used in k8s, prepend the hostname to the log file name.
Mode string `yaml:"Mode" default:"console"`
// Encoding represents the encoding type, default is `json`.
// json: json encoding.
// plain: plain text encoding, typically used in development.
Encoding string `yaml:"Encoding" default:"json"`
// TimeFormat represents the time format, default is `2006-01-02T15:04:05.000Z07:00`.
TimeFormat string `yaml:"TimeFormat" default:"2006-01-02T15:04:05.000Z07:00"`
// Path represents the log file path, default is `logs`.
Path string `yaml:"Path" default:"logs"`
// Level represents the log level, default is `info`.
Level string `yaml:"Level" default:"info"`
// MaxContentLength represents the max content bytes, default is no limit.
MaxContentLength uint32 `yaml:"MaxContentLength" default:"0"`
// Compress represents whether to compress the log file, default is `false`.
Compress bool `yaml:"Compress" default:"false"`
// Stat represents whether to log statistics, default is `true`.
Stat bool `yaml:"Stat" default:"true"`
// KeepDays represents how many days the log files will be kept. Default to keep all files.
// Only take effect when Mode is `file` or `volume`, both work when Rotation is `daily` or `size`.
KeepDays int `yaml:"KeepDays" default:"0"`
// StackCooldownMillis represents the cooldown time for stack logging, default is 100ms.
StackCooldownMillis int `yaml:"StackCooldownMillis" default:"100"`
// MaxBackups represents how many backup log files will be kept. 0 means all files will be kept forever.
// Only take effect when RotationRuleType is `size`.
// Even though `MaxBackups` sets 0, log files will still be removed
// if the `KeepDays` limitation is reached.
MaxBackups int `yaml:"MaxBackups" default:"0"`
// MaxSize represents how much space the writing log file takes up. 0 means no limit. The unit is `MB`.
// Only take effect when RotationRuleType is `size`
MaxSize int `yaml:"MaxSize" default:"0"`
// Rotation represents the type of log rotation rule. Default is `daily`.
// daily: daily rotation.
// size: size limited rotation.
Rotation string `yaml:"Rotation" default:"daily"`
// FileTimeFormat represents the time format for file name, default is `2006-01-02T15:04:05.000Z07:00`.
FileTimeFormat string `yaml:"FileTimeFormat" default:"2006-01-02T15:04:05.000Z07:00"`
}
+48
View File
@@ -0,0 +1,48 @@
package logger
import (
"context"
"sync"
"sync/atomic"
)
var (
fieldsContextKey contextKey
globalFields atomic.Value
globalFieldsLock sync.Mutex
)
type contextKey struct{}
// AddGlobalFields adds global fields.
func AddGlobalFields(fields ...LogField) {
globalFieldsLock.Lock()
defer globalFieldsLock.Unlock()
old := globalFields.Load()
if old == nil {
globalFields.Store(append([]LogField(nil), fields...))
} else {
globalFields.Store(append(old.([]LogField), fields...))
}
}
// ContextWithFields returns a new context with the given fields.
func ContextWithFields(ctx context.Context, fields ...LogField) context.Context {
if val := ctx.Value(fieldsContextKey); val != nil {
if arr, ok := val.([]LogField); ok {
allFields := make([]LogField, 0, len(arr)+len(fields))
allFields = append(allFields, arr...)
allFields = append(allFields, fields...)
return context.WithValue(ctx, fieldsContextKey, allFields)
}
}
return context.WithValue(ctx, fieldsContextKey, fields)
}
// WithFields returns a new logger with the given fields.
// deprecated: use ContextWithFields instead.
func WithFields(ctx context.Context, fields ...LogField) context.Context {
return ContextWithFields(ctx, fields...)
}
+122
View File
@@ -0,0 +1,122 @@
package logger
import (
"bytes"
"context"
"encoding/json"
"strconv"
"sync"
"sync/atomic"
"testing"
"github.com/stretchr/testify/assert"
)
func TestAddGlobalFields(t *testing.T) {
var buf bytes.Buffer
writer := NewWriter(&buf)
old := Reset()
SetWriter(writer)
defer SetWriter(old)
Info("hello")
buf.Reset()
AddGlobalFields(Field("a", "1"), Field("b", "2"))
AddGlobalFields(Field("c", "3"))
Info("world")
var m map[string]any
assert.NoError(t, json.Unmarshal(buf.Bytes(), &m))
assert.Equal(t, "1", m["a"])
assert.Equal(t, "2", m["b"])
assert.Equal(t, "3", m["c"])
}
func TestContextWithFields(t *testing.T) {
ctx := ContextWithFields(context.Background(), Field("a", 1), Field("b", 2))
vals := ctx.Value(fieldsContextKey)
assert.NotNil(t, vals)
fields, ok := vals.([]LogField)
assert.True(t, ok)
assert.EqualValues(t, []LogField{Field("a", 1), Field("b", 2)}, fields)
}
func TestWithFields(t *testing.T) {
ctx := WithFields(context.Background(), Field("a", 1), Field("b", 2))
vals := ctx.Value(fieldsContextKey)
assert.NotNil(t, vals)
fields, ok := vals.([]LogField)
assert.True(t, ok)
assert.EqualValues(t, []LogField{Field("a", 1), Field("b", 2)}, fields)
}
func TestWithFieldsAppend(t *testing.T) {
type ctxKey string
var dummyKey ctxKey = "dummyKey"
ctx := context.WithValue(context.Background(), dummyKey, "dummy")
ctx = ContextWithFields(ctx, Field("a", 1), Field("b", 2))
ctx = ContextWithFields(ctx, Field("c", 3), Field("d", 4))
vals := ctx.Value(fieldsContextKey)
assert.NotNil(t, vals)
fields, ok := vals.([]LogField)
assert.True(t, ok)
assert.Equal(t, "dummy", ctx.Value(dummyKey))
assert.EqualValues(t, []LogField{
Field("a", 1),
Field("b", 2),
Field("c", 3),
Field("d", 4),
}, fields)
}
func TestWithFieldsAppendCopy(t *testing.T) {
const count = 10
ctx := context.Background()
for i := 0; i < count; i++ {
ctx = ContextWithFields(ctx, Field(strconv.Itoa(i), 1))
}
af := Field("foo", 1)
bf := Field("bar", 2)
ctxa := ContextWithFields(ctx, af)
ctxb := ContextWithFields(ctx, bf)
assert.EqualValues(t, af, ctxa.Value(fieldsContextKey).([]LogField)[count])
assert.EqualValues(t, bf, ctxb.Value(fieldsContextKey).([]LogField)[count])
}
func BenchmarkAtomicValue(b *testing.B) {
b.ReportAllocs()
var container atomic.Value
vals := []LogField{
Field("a", "b"),
Field("c", "d"),
Field("e", "f"),
}
container.Store(&vals)
for i := 0; i < b.N; i++ {
val := container.Load()
if val != nil {
_ = *val.(*[]LogField)
}
}
}
func BenchmarkRWMutex(b *testing.B) {
b.ReportAllocs()
var lock sync.RWMutex
vals := []LogField{
Field("a", "b"),
Field("c", "d"),
Field("e", "f"),
}
for i := 0; i < b.N; i++ {
lock.RLock()
_ = vals
lock.RUnlock()
}
}
+40
View File
@@ -0,0 +1,40 @@
package logger
import (
"io"
"os"
)
var fileSys realFileSystem
type (
fileSystem interface {
Close(closer io.Closer) error
Copy(writer io.Writer, reader io.Reader) (int64, error)
Create(name string) (*os.File, error)
Open(name string) (*os.File, error)
Remove(name string) error
}
realFileSystem struct{}
)
func (fs realFileSystem) Close(closer io.Closer) error {
return closer.Close()
}
func (fs realFileSystem) Copy(writer io.Writer, reader io.Reader) (int64, error) {
return io.Copy(writer, reader)
}
func (fs realFileSystem) Create(name string) (*os.File, error) {
return os.Create(name)
}
func (fs realFileSystem) Open(name string) (*os.File, error) {
return os.Open(name)
}
func (fs realFileSystem) Remove(name string) error {
return os.Remove(name)
}
+67
View File
@@ -0,0 +1,67 @@
package logger
import (
"context"
"fmt"
"time"
"gorm.io/gorm/logger"
)
type GormLogger struct {
}
const TAG = "[GORM]"
func (l *GormLogger) LogMode(logger.LogLevel) logger.Interface {
var sysLevel string
switch logLevel {
case DebugLevel:
sysLevel = "debug"
case InfoLevel:
sysLevel = "info"
case SevereLevel:
sysLevel = "severe"
case disableLevel:
sysLevel = "disable"
default:
sysLevel = "unknown"
}
Infof("%s System Log Level is %s", TAG, sysLevel)
return l
}
func (l *GormLogger) Info(ctx context.Context, str string, args ...interface{}) {
WithContext(ctx).WithCallerSkip(6).Infof("%s Info: %s", TAG, str, args)
}
func (l *GormLogger) Warn(ctx context.Context, str string, args ...interface{}) {
WithContext(ctx).WithCallerSkip(6).Infof("%s Warn: %s", TAG, str, args)
}
func (l *GormLogger) Error(ctx context.Context, str string, args ...interface{}) {
WithContext(ctx).WithCallerSkip(6).Errorf("%s Error: %s", TAG, str, args)
}
func (l *GormLogger) Trace(ctx context.Context, begin time.Time, fc func() (sql string, rowsAffected int64), err error) {
sql, rowsAffected := fc()
fields := []LogField{
{
Key: "sql",
Value: sql,
},
{
Key: "rows",
Value: rowsAffected,
},
}
if err != nil {
fields = append(fields, LogField{
Key: "error",
Value: err.Error(),
})
WithContext(ctx).WithCallerSkip(6).WithDuration(time.Since(begin)).Errorw(TAG, fields...)
} else {
WithContext(ctx).WithCallerSkip(6).WithDuration(time.Since(begin)).Infow(fmt.Sprintf("%s SQL Executed", TAG), fields...)
}
}
+27
View File
@@ -0,0 +1,27 @@
package logger
// A LessLogger is a logger that controls to log once during the given duration.
type LessLogger struct {
*limitedExecutor
}
// NewLessLogger returns a LessLogger.
func NewLessLogger(milliseconds int) *LessLogger {
return &LessLogger{
limitedExecutor: newLimitedExecutor(milliseconds),
}
}
// Error logs v into error log or discard it if more than once in the given duration.
func (logger *LessLogger) Error(v ...any) {
logger.logOrDiscard(func() {
Error(v...)
})
}
// Errorf logs v with format into error log or discard it if more than once in the given duration.
func (logger *LessLogger) Errorf(format string, v ...any) {
logger.logOrDiscard(func() {
Errorf(format, v...)
})
}
+35
View File
@@ -0,0 +1,35 @@
package logger
import (
"log"
"strings"
"testing"
"github.com/stretchr/testify/assert"
)
func TestLessLogger_Error(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
l := NewLessLogger(500)
for i := 0; i < 100; i++ {
l.Error("hello")
}
log.Print(w.String())
assert.Equal(t, 1, strings.Count(w.String(), "\n"))
}
func TestLessLogger_Errorf(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
l := NewLessLogger(500)
for i := 0; i < 100; i++ {
l.Errorf("hello")
}
assert.Equal(t, 1, strings.Count(w.String(), "\n"))
}
+22
View File
@@ -0,0 +1,22 @@
package logger
import "io"
type lessWriter struct {
*limitedExecutor
writer io.Writer
}
func newLessWriter(writer io.Writer, milliseconds int) *lessWriter {
return &lessWriter{
limitedExecutor: newLimitedExecutor(milliseconds),
writer: writer,
}
}
func (w *lessWriter) Write(p []byte) (n int, err error) {
w.logOrDiscard(func() {
_, _ = w.writer.Write(p)
})
return len(p), nil
}
+19
View File
@@ -0,0 +1,19 @@
package logger
import (
"strings"
"testing"
"github.com/stretchr/testify/assert"
)
func TestLessWriter(t *testing.T) {
var builder strings.Builder
w := newLessWriter(&builder, 500)
for i := 0; i < 100; i++ {
_, err := w.Write([]byte("hello"))
assert.Nil(t, err)
}
assert.Equal(t, "hello", builder.String())
}
+42
View File
@@ -0,0 +1,42 @@
package logger
import (
"sync/atomic"
"time"
"github.com/perfect-panel/ppanel-server/pkg/syncx"
"github.com/perfect-panel/ppanel-server/pkg/timex"
)
type limitedExecutor struct {
threshold time.Duration
lastTime *syncx.AtomicDuration
discarded uint32
}
func newLimitedExecutor(milliseconds int) *limitedExecutor {
return &limitedExecutor{
threshold: time.Duration(milliseconds) * time.Millisecond,
lastTime: syncx.NewAtomicDuration(),
}
}
func (le *limitedExecutor) logOrDiscard(execute func()) {
if le == nil || le.threshold <= 0 {
execute()
return
}
now := timex.Now()
if now-le.lastTime.Load() <= le.threshold {
atomic.AddUint32(&le.discarded, 1)
} else {
le.lastTime.Set(now)
discarded := atomic.SwapUint32(&le.discarded, 0)
if discarded > 0 {
Errorf("Discarded %d error messages", discarded)
}
execute()
}
}
+62
View File
@@ -0,0 +1,62 @@
package logger
import (
"sync/atomic"
"testing"
"time"
"github.com/perfect-panel/ppanel-server/pkg/timex"
"github.com/stretchr/testify/assert"
)
func TestLimitedExecutor_logOrDiscard(t *testing.T) {
tests := []struct {
name string
threshold time.Duration
lastTime time.Duration
discarded uint32
executed bool
}{
{
name: "nil executor",
executed: true,
},
{
name: "regular",
threshold: time.Hour,
lastTime: timex.Now(),
discarded: 10,
executed: false,
},
{
name: "slow",
threshold: time.Duration(1),
lastTime: -1000,
discarded: 10,
executed: true,
},
}
for _, test := range tests {
test := test
t.Run(test.name, func(t *testing.T) {
t.Parallel()
executor := newLimitedExecutor(0)
executor.threshold = test.threshold
executor.discarded = test.discarded
executor.lastTime.Set(test.lastTime)
var run int32
executor.logOrDiscard(func() {
atomic.AddInt32(&run, 1)
})
if test.executed {
assert.Equal(t, int32(1), atomic.LoadInt32(&run))
} else {
assert.Equal(t, int32(0), atomic.LoadInt32(&run))
assert.Equal(t, test.discarded+1, atomic.LoadUint32(&executor.discarded))
}
})
}
}
+50
View File
@@ -0,0 +1,50 @@
package logger
import (
"context"
"time"
)
// A Logger represents a logger.
type Logger interface {
// Debug logs a message at debug level.
Debug(...any)
// Debugf logs a message at debug level.
Debugf(string, ...any)
// Debugv logs a message at debug level.
Debugv(any)
// Debugw logs a message at debug level.
Debugw(string, ...LogField)
// Error logs a message at error level.
Error(...any)
// Errorf logs a message at error level.
Errorf(string, ...any)
// Errorv logs a message at error level.
Errorv(any)
// Errorw logs a message at error level.
Errorw(string, ...LogField)
// Info logs a message at info level.
Info(...any)
// Infof logs a message at info level.
Infof(string, ...any)
// Infov logs a message at info level.
Infov(any)
// Infow logs a message at info level.
Infow(string, ...LogField)
// Slow logs a message at slow level.
Slow(...any)
// Slowf logs a message at slow level.
Slowf(string, ...any)
// Slowv logs a message at slow level.
Slowv(any)
// Sloww logs a message at slow level.
Sloww(string, ...LogField)
// WithCallerSkip returns a new logger with the given caller skip.
WithCallerSkip(skip int) Logger
// WithContext returns a new logger with the given context.
WithContext(ctx context.Context) Logger
// WithDuration returns a new logger with the given duration.
WithDuration(d time.Duration) Logger
// WithFields returns a new logger with the given fields.
WithFields(fields ...LogField) Logger
}
+578
View File
@@ -0,0 +1,578 @@
package logger
import (
"fmt"
"io"
"log"
"os"
"path"
"reflect"
"runtime/debug"
"sync"
"sync/atomic"
"time"
)
const callerDepth = 4
var (
timeFormat = "2006-01-02T15:04:05.000Z07:00"
encoding uint32 = jsonEncodingType
// maxContentLength is used to truncate the log content, 0 for not truncating.
maxContentLength uint32
// use uint32 for atomic operations
disableStat uint32
logLevel uint32
options logOptions
writer = new(atomicWriter)
setupOnce sync.Once
)
type (
// LogField is a key-value pair that will be added to the log entry.
LogField struct {
Key string
Value any
}
// LogOption defines the method to customize the logging.
LogOption func(options *logOptions)
logEntry map[string]any
logOptions struct {
gzipEnabled bool
logStackCooldownMills int
keepDays int
maxBackups int
maxSize int
rotationRule string
}
)
// AddWriter adds a new writer.
// If there is already a writer, the new writer will be added to the writer chain.
// For example, to write logs to both file and console, if there is already a file writer,
// ```go
// logx.AddWriter(logx.NewWriter(os.Stdout))
// ```
func AddWriter(w Writer) {
ow := Reset()
if ow == nil {
SetWriter(w)
} else {
// no need to check if the existing writer is a comboWriter,
// because it is not common to add more than one writer.
// even more than one writer, the behavior is the same.
SetWriter(comboWriter{
writers: []Writer{ow, w},
})
}
}
// Alert alerts v in alert level, and the message is written to error log.
func Alert(v string) {
getWriter().Alert(v)
}
// Close closes the logging.
func Close() error {
if w := writer.Swap(nil); w != nil {
return w.(io.Closer).Close()
}
return nil
}
// Debug writes v into access log.
func Debug(v ...any) {
if shallLog(DebugLevel) {
writeDebug(fmt.Sprint(v...))
}
}
// Debugf writes v with format into access log.
func Debugf(format string, v ...any) {
if shallLog(DebugLevel) {
writeDebug(fmt.Sprintf(format, v...))
}
}
// Debugv writes v into access log with json content.
func Debugv(v any) {
if shallLog(DebugLevel) {
writeDebug(v)
}
}
// Debugw writes msg along with fields into the access log.
func Debugw(msg string, fields ...LogField) {
if shallLog(DebugLevel) {
writeDebug(msg, fields...)
}
}
// Disable disables the logging.
func Disable() {
atomic.StoreUint32(&logLevel, disableLevel)
writer.Store(nopWriter{})
}
// DisableStat disables the stat logs.
func DisableStat() {
atomic.StoreUint32(&disableStat, 1)
}
// Error writes v into error log.
func Error(v ...any) {
if shallLog(ErrorLevel) {
writeError(fmt.Sprint(v...))
}
}
// Errorf writes v with format into error log.
func Errorf(format string, v ...any) {
if shallLog(ErrorLevel) {
writeError(fmt.Errorf(format, v...).Error())
}
}
// ErrorStack writes v along with call stack into error log.
func ErrorStack(v ...any) {
if shallLog(ErrorLevel) {
// there is newline in stack string
writeStack(fmt.Sprint(v...))
}
}
// ErrorStackf writes v along with call stack in format into error log.
func ErrorStackf(format string, v ...any) {
if shallLog(ErrorLevel) {
// there is newline in stack string
writeStack(fmt.Sprintf(format, v...))
}
}
// Errorv writes v into error log with json content.
// No call stack attached, because not elegant to pack the messages.
func Errorv(v any) {
if shallLog(ErrorLevel) {
writeError(v)
}
}
// Errorw writes msg along with fields into the error log.
func Errorw(msg string, fields ...LogField) {
if shallLog(ErrorLevel) {
writeError(msg, fields...)
}
}
// Field returns a LogField for the given key and value.
func Field(key string, value any) LogField {
switch val := value.(type) {
case error:
return LogField{Key: key, Value: encodeError(val)}
case []error:
var errs []string
for _, err := range val {
errs = append(errs, encodeError(err))
}
return LogField{Key: key, Value: errs}
case time.Duration:
return LogField{Key: key, Value: fmt.Sprint(val)}
case []time.Duration:
var durs []string
for _, dur := range val {
durs = append(durs, fmt.Sprint(dur))
}
return LogField{Key: key, Value: durs}
case []time.Time:
var times []string
for _, t := range val {
times = append(times, fmt.Sprint(t))
}
return LogField{Key: key, Value: times}
case fmt.Stringer:
return LogField{Key: key, Value: encodeStringer(val)}
case []fmt.Stringer:
var strs []string
for _, str := range val {
strs = append(strs, encodeStringer(str))
}
return LogField{Key: key, Value: strs}
default:
return LogField{Key: key, Value: val}
}
}
// Info writes v into access log.
func Info(v ...any) {
if shallLog(InfoLevel) {
writeInfo(fmt.Sprint(v...))
}
}
// Infof writes v with format into access log.
func Infof(format string, v ...any) {
if shallLog(InfoLevel) {
writeInfo(fmt.Sprintf(format, v...))
}
}
// Infov writes v into access log with json content.
func Infov(v any) {
if shallLog(InfoLevel) {
writeInfo(v)
}
}
// Infow writes msg along with fields into the access log.
func Infow(msg string, fields ...LogField) {
if shallLog(InfoLevel) {
writeInfo(msg, fields...)
}
}
// Must checks if err is nil, otherwise logs the error and exits.
func Must(err error) {
if err == nil {
return
}
msg := fmt.Sprintf("%+v\n\n%s", err.Error(), debug.Stack())
log.Print(msg)
getWriter().Severe(msg)
if ExitOnFatal.True() {
os.Exit(1)
} else {
panic(msg)
}
}
// MustSetup sets up logging with given config c. It exits on error.
func MustSetup(c LogConf) {
Must(SetUp(c))
}
// Reset clears the writer and resets the log level.
func Reset() Writer {
return writer.Swap(nil)
}
// SetLevel sets the logging level. It can be used to suppress some logs.
func SetLevel(level uint32) {
atomic.StoreUint32(&logLevel, level)
}
// SetWriter sets the logging writer. It can be used to customize the logging.
func SetWriter(w Writer) {
if atomic.LoadUint32(&logLevel) != disableLevel {
writer.Store(w)
}
}
// SetUp sets up the logx.
// If already set up, return nil.
// We allow SetUp to be called multiple times, because, for example,
// we need to allow different service frameworks to initialize logx respectively.
func SetUp(c LogConf) (err error) {
// Ignore the later SetUp calls.
// Because multiple services in one process might call SetUp respectively.
// Need to wait for the first caller to complete the execution.
setupOnce.Do(func() {
setupLogLevel(c)
if !c.Stat {
DisableStat()
}
if len(c.TimeFormat) > 0 {
timeFormat = c.TimeFormat
}
if len(c.FileTimeFormat) > 0 {
fileTimeFormat = c.FileTimeFormat
}
atomic.StoreUint32(&maxContentLength, c.MaxContentLength)
switch c.Encoding {
case plainEncoding:
atomic.StoreUint32(&encoding, plainEncodingType)
default:
atomic.StoreUint32(&encoding, jsonEncodingType)
}
switch c.Mode {
case fileMode:
err = setupWithFiles(c)
case volumeMode:
err = setupWithVolume(c)
default:
setupWithConsole()
}
})
return
}
// Severe writes v into severe log.
func Severe(v ...any) {
if shallLog(SevereLevel) {
writeSevere(fmt.Sprint(v...))
}
}
// Severef writes v with format into severe log.
func Severef(format string, v ...any) {
if shallLog(SevereLevel) {
writeSevere(fmt.Sprintf(format, v...))
}
}
// Slow writes v into slow log.
func Slow(v ...any) {
if shallLog(ErrorLevel) {
writeSlow(fmt.Sprint(v...))
}
}
// Slowf writes v with format into slow log.
func Slowf(format string, v ...any) {
if shallLog(ErrorLevel) {
writeSlow(fmt.Sprintf(format, v...))
}
}
// Slowv writes v into slow log with json content.
func Slowv(v any) {
if shallLog(ErrorLevel) {
writeSlow(v)
}
}
// Sloww writes msg along with fields into slow log.
func Sloww(msg string, fields ...LogField) {
if shallLog(ErrorLevel) {
writeSlow(msg, fields...)
}
}
// Stat writes v into stat log.
func Stat(v ...any) {
if shallLogStat() && shallLog(InfoLevel) {
writeStat(fmt.Sprint(v...))
}
}
// Statf writes v with format into stat log.
func Statf(format string, v ...any) {
if shallLogStat() && shallLog(InfoLevel) {
writeStat(fmt.Sprintf(format, v...))
}
}
// WithCooldownMillis customizes logging on writing call stack interval.
func WithCooldownMillis(millis int) LogOption {
return func(opts *logOptions) {
opts.logStackCooldownMills = millis
}
}
// WithKeepDays customizes logging to keep logs with days.
func WithKeepDays(days int) LogOption {
return func(opts *logOptions) {
opts.keepDays = days
}
}
// WithGzip customizes logging to automatically gzip the log files.
func WithGzip() LogOption {
return func(opts *logOptions) {
opts.gzipEnabled = true
}
}
// WithMaxBackups customizes how many log files backups will be kept.
func WithMaxBackups(count int) LogOption {
return func(opts *logOptions) {
opts.maxBackups = count
}
}
// WithMaxSize customizes how much space the writing log file can take up.
func WithMaxSize(size int) LogOption {
return func(opts *logOptions) {
opts.maxSize = size
}
}
// WithRotation customizes which log rotation rule to use.
func WithRotation(r string) LogOption {
return func(opts *logOptions) {
opts.rotationRule = r
}
}
func addCaller(fields ...LogField) []LogField {
return append(fields, Field(callerKey, getCaller(callerDepth)))
}
func createOutput(path string) (io.WriteCloser, error) {
if len(path) == 0 {
return nil, ErrLogPathNotSet
}
var rule RotateRule
switch options.rotationRule {
case sizeRotationRule:
rule = NewSizeLimitRotateRule(path, backupFileDelimiter, options.keepDays, options.maxSize,
options.maxBackups, options.gzipEnabled)
default:
rule = DefaultRotateRule(path, backupFileDelimiter, options.keepDays, options.gzipEnabled)
}
return NewLogger(path, rule, options.gzipEnabled)
}
func encodeError(err error) (ret string) {
return encodeWithRecover(err, func() string {
return err.Error()
})
}
func encodeStringer(v fmt.Stringer) (ret string) {
return encodeWithRecover(v, func() string {
return v.String()
})
}
func encodeWithRecover(arg any, fn func() string) (ret string) {
defer func() {
if err := recover(); err != nil {
if v := reflect.ValueOf(arg); v.Kind() == reflect.Ptr && v.IsNil() {
ret = nilAngleString
} else {
ret = fmt.Sprintf("panic: %v", err)
}
}
}()
return fn()
}
func getWriter() Writer {
w := writer.Load()
if w == nil {
w = writer.StoreIfNil(newConsoleWriter())
}
return w
}
func handleOptions(opts []LogOption) {
for _, opt := range opts {
opt(&options)
}
}
func setupLogLevel(c LogConf) {
switch c.Level {
case levelDebug:
SetLevel(DebugLevel)
case levelInfo:
SetLevel(InfoLevel)
case levelError:
SetLevel(ErrorLevel)
case levelSevere:
SetLevel(SevereLevel)
}
}
func setupWithConsole() {
SetWriter(newConsoleWriter())
}
func setupWithFiles(c LogConf) error {
w, err := newFileWriter(c)
if err != nil {
return err
}
SetWriter(w)
return nil
}
func setupWithVolume(c LogConf) error {
if len(c.ServiceName) == 0 {
return ErrLogServiceNameNotSet
}
hostname, _ := os.Hostname()
c.Path = path.Join(c.Path, c.ServiceName, hostname)
return setupWithFiles(c)
}
func shallLog(level uint32) bool {
return atomic.LoadUint32(&logLevel) <= level
}
func shallLogStat() bool {
return atomic.LoadUint32(&disableStat) == 0
}
// writeDebug writes v into debug log.
// Not checking shallLog here is for performance consideration.
// If we check shallLog here, the fmt.Sprint might be called even if the log level is not enabled.
// The caller should check shallLog before calling this function.
func writeDebug(val any, fields ...LogField) {
getWriter().Debug(val, addCaller(fields...)...)
}
// writeError writes v into the error log.
// Not checking shallLog here is for performance consideration.
// If we check shallLog here, the fmt.Sprint might be called even if the log level is not enabled.
// The caller should check shallLog before calling this function.
func writeError(val any, fields ...LogField) {
getWriter().Error(val, addCaller(fields...)...)
}
// writeInfo writes v into info log.
// Not checking shallLog here is for performance consideration.
// If we check shallLog here, the fmt.Sprint might be called even if the log level is not enabled.
// The caller should check shallLog before calling this function.
func writeInfo(val any, fields ...LogField) {
getWriter().Info(val, addCaller(fields...)...)
}
// writeSevere writes v into severe log.
// Not checking shallLog here is for performance consideration.
// If we check shallLog here, the fmt.Sprint might be called even if the log level is not enabled.
// The caller should check shallLog before calling this function.
func writeSevere(msg string) {
getWriter().Severe(fmt.Sprintf("%s\n%s", msg, string(debug.Stack())))
}
// writeSlow writes v into slow log.
// Not checking shallLog here is for performance consideration.
// If we check shallLog here, the fmt.Sprint might be called even if the log level is not enabled.
// The caller should check shallLog before calling this function.
func writeSlow(val any, fields ...LogField) {
getWriter().Slow(val, addCaller(fields...)...)
}
// writeStack writes v into stack log.
// Not checking shallLog here is for performance consideration.
// If we check shallLog here, the fmt.Sprint might be called even if the log level is not enabled.
// The caller should check shallLog before calling this function.
func writeStack(msg string) {
getWriter().Stack(fmt.Sprintf("%s\n%s", msg, string(debug.Stack())))
}
// writeStat writes v into the stat log.
// Not checking shallLog here is for performance consideration.
// If we check shallLog here, the fmt.Sprint might be called even if the log level is not enabled.
// The caller should check shallLog before calling this function.
func writeStat(msg string) {
getWriter().Stat(msg, addCaller()...)
}
+931
View File
@@ -0,0 +1,931 @@
package logger
import (
"encoding/json"
"errors"
"fmt"
"io"
"log"
"os"
"reflect"
"runtime"
"strings"
"sync"
"sync/atomic"
"testing"
"time"
"github.com/stretchr/testify/assert"
)
var (
s = []byte("Sending #11 notification (id: 1451875113812010473) in #1 connection")
pool = make(chan []byte, 1)
_ Writer = (*mockWriter)(nil)
)
func init() {
ExitOnFatal.Set(false)
}
type mockWriter struct {
lock sync.Mutex
builder strings.Builder
}
func (mw *mockWriter) Alert(v any) {
mw.lock.Lock()
defer mw.lock.Unlock()
output(&mw.builder, levelAlert, v)
}
func (mw *mockWriter) Debug(v any, fields ...LogField) {
mw.lock.Lock()
defer mw.lock.Unlock()
output(&mw.builder, levelDebug, v, fields...)
}
func (mw *mockWriter) Error(v any, fields ...LogField) {
mw.lock.Lock()
defer mw.lock.Unlock()
output(&mw.builder, levelError, v, fields...)
}
func (mw *mockWriter) Info(v any, fields ...LogField) {
mw.lock.Lock()
defer mw.lock.Unlock()
output(&mw.builder, levelInfo, v, fields...)
}
func (mw *mockWriter) Severe(v any) {
mw.lock.Lock()
defer mw.lock.Unlock()
output(&mw.builder, levelSevere, v)
}
func (mw *mockWriter) Slow(v any, fields ...LogField) {
mw.lock.Lock()
defer mw.lock.Unlock()
output(&mw.builder, levelSlow, v, fields...)
}
func (mw *mockWriter) Stack(v any) {
mw.lock.Lock()
defer mw.lock.Unlock()
output(&mw.builder, levelError, v)
}
func (mw *mockWriter) Stat(v any, fields ...LogField) {
mw.lock.Lock()
defer mw.lock.Unlock()
output(&mw.builder, levelStat, v, fields...)
}
func (mw *mockWriter) Close() error {
return nil
}
func (mw *mockWriter) Contains(text string) bool {
mw.lock.Lock()
defer mw.lock.Unlock()
return strings.Contains(mw.builder.String(), text)
}
func (mw *mockWriter) Reset() {
mw.lock.Lock()
defer mw.lock.Unlock()
mw.builder.Reset()
}
func (mw *mockWriter) String() string {
mw.lock.Lock()
defer mw.lock.Unlock()
return mw.builder.String()
}
func TestField(t *testing.T) {
tests := []struct {
name string
f LogField
want map[string]any
}{
{
name: "error",
f: Field("foo", errors.New("bar")),
want: map[string]any{
"foo": "bar",
},
},
{
name: "errors",
f: Field("foo", []error{errors.New("bar"), errors.New("baz")}),
want: map[string]any{
"foo": []any{"bar", "baz"},
},
},
{
name: "strings",
f: Field("foo", []string{"bar", "baz"}),
want: map[string]any{
"foo": []any{"bar", "baz"},
},
},
{
name: "duration",
f: Field("foo", time.Second),
want: map[string]any{
"foo": "1s",
},
},
{
name: "durations",
f: Field("foo", []time.Duration{time.Second, 2 * time.Second}),
want: map[string]any{
"foo": []any{"1s", "2s"},
},
},
{
name: "times",
f: Field("foo", []time.Time{
time.Date(2020, time.January, 1, 0, 0, 0, 0, time.UTC),
time.Date(2020, time.January, 2, 0, 0, 0, 0, time.UTC),
}),
want: map[string]any{
"foo": []any{"2020-01-01 00:00:00 +0000 UTC", "2020-01-02 00:00:00 +0000 UTC"},
},
},
{
name: "stringer",
f: Field("foo", ValStringer{val: "bar"}),
want: map[string]any{
"foo": "bar",
},
},
{
name: "stringers",
f: Field("foo", []fmt.Stringer{ValStringer{val: "bar"}, ValStringer{val: "baz"}}),
want: map[string]any{
"foo": []any{"bar", "baz"},
},
},
}
for _, test := range tests {
test := test
t.Run(test.name, func(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
Infow("foo", test.f)
validateFields(t, w.String(), test.want)
})
}
}
func TestFileLineFileMode(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
file, line := getFileLine()
Error("anything")
assert.True(t, w.Contains(fmt.Sprintf("%s:%d", file, line+1)))
file, line = getFileLine()
Errorf("anything %s", "format")
assert.True(t, w.Contains(fmt.Sprintf("%s:%d", file, line+1)))
}
func TestFileLineConsoleMode(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
file, line := getFileLine()
Error("anything")
assert.True(t, w.Contains(fmt.Sprintf("%s:%d", file, line+1)))
w.Reset()
file, line = getFileLine()
Errorf("anything %s", "format")
assert.True(t, w.Contains(fmt.Sprintf("%s:%d", file, line+1)))
}
func TestMust(t *testing.T) {
assert.Panics(t, func() {
Must(errors.New("foo"))
})
}
func TestStructedLogAlert(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelAlert, w, func(v ...any) {
Alert(fmt.Sprint(v...))
})
}
func TestStructedLogDebug(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelDebug, w, func(v ...any) {
Debug(v...)
})
}
func TestStructedLogDebugf(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelDebug, w, func(v ...any) {
Debugf(fmt.Sprint(v...))
})
}
func TestStructedLogDebugv(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelDebug, w, func(v ...any) {
Debugv(fmt.Sprint(v...))
})
}
func TestStructedLogDebugw(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelDebug, w, func(v ...any) {
Debugw(fmt.Sprint(v...), Field("foo", time.Second))
})
}
func TestStructedLogError(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelError, w, func(v ...any) {
Error(v...)
})
}
func TestStructedLogErrorf(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelError, w, func(v ...any) {
Errorf("%s", fmt.Sprint(v...))
})
}
func TestStructedLogErrorv(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelError, w, func(v ...any) {
Errorv(fmt.Sprint(v...))
})
}
func TestStructedLogErrorw(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelError, w, func(v ...any) {
Errorw(fmt.Sprint(v...), Field("foo", "bar"))
})
}
func TestStructedLogInfo(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelInfo, w, func(v ...any) {
Info(v...)
})
}
func TestStructedLogInfof(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelInfo, w, func(v ...any) {
Infof("%s", fmt.Sprint(v...))
})
}
func TestStructedLogInfov(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelInfo, w, func(v ...any) {
Infov(fmt.Sprint(v...))
})
}
func TestStructedLogInfow(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelInfo, w, func(v ...any) {
Infow(fmt.Sprint(v...), Field("foo", "bar"))
})
}
func TestStructedLogFieldNil(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
assert.NotPanics(t, func() {
var s *string
Infow("test", Field("bb", s))
var d *nilStringer
Infow("test", Field("bb", d))
var e *nilError
Errorw("test", Field("bb", e))
})
assert.NotPanics(t, func() {
var p panicStringer
Infow("test", Field("bb", p))
var ps innerPanicStringer
Infow("test", Field("bb", ps))
})
}
func TestStructedLogInfoConsoleAny(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLogConsole(t, w, func(v ...any) {
old := atomic.LoadUint32(&encoding)
atomic.StoreUint32(&encoding, plainEncodingType)
defer func() {
atomic.StoreUint32(&encoding, old)
}()
Infov(v)
})
}
func TestStructedLogInfoConsoleAnyString(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLogConsole(t, w, func(v ...any) {
old := atomic.LoadUint32(&encoding)
atomic.StoreUint32(&encoding, plainEncodingType)
defer func() {
atomic.StoreUint32(&encoding, old)
}()
Infov(fmt.Sprint(v...))
})
}
func TestStructedLogInfoConsoleAnyError(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLogConsole(t, w, func(v ...any) {
old := atomic.LoadUint32(&encoding)
atomic.StoreUint32(&encoding, plainEncodingType)
defer func() {
atomic.StoreUint32(&encoding, old)
}()
Infov(errors.New(fmt.Sprint(v...)))
})
}
func TestStructedLogInfoConsoleAnyStringer(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLogConsole(t, w, func(v ...any) {
old := atomic.LoadUint32(&encoding)
atomic.StoreUint32(&encoding, plainEncodingType)
defer func() {
atomic.StoreUint32(&encoding, old)
}()
Infov(ValStringer{
val: fmt.Sprint(v...),
})
})
}
func TestStructedLogInfoConsoleText(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLogConsole(t, w, func(v ...any) {
old := atomic.LoadUint32(&encoding)
atomic.StoreUint32(&encoding, plainEncodingType)
defer func() {
atomic.StoreUint32(&encoding, old)
}()
Info(fmt.Sprint(v...))
})
}
func TestStructedLogSlow(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelSlow, w, func(v ...any) {
Slow(v...)
})
}
func TestStructedLogSlowf(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelSlow, w, func(v ...any) {
Slowf(fmt.Sprint(v...))
})
}
func TestStructedLogSlowv(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelSlow, w, func(v ...any) {
Slowv(fmt.Sprint(v...))
})
}
func TestStructedLogSloww(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelSlow, w, func(v ...any) {
Sloww(fmt.Sprint(v...), Field("foo", time.Second))
})
}
func TestStructedLogStat(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelStat, w, func(v ...any) {
Stat(v...)
})
}
func TestStructedLogStatf(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelStat, w, func(v ...any) {
Statf(fmt.Sprint(v...))
})
}
func TestStructedLogSevere(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelSevere, w, func(v ...any) {
Severe(v...)
})
}
func TestStructedLogSeveref(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
doTestStructedLog(t, levelSevere, w, func(v ...any) {
Severef(fmt.Sprint(v...))
})
}
func TestStructedLogWithDuration(t *testing.T) {
const message = "hello there"
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
WithDuration(time.Second).Info(message)
var entry map[string]any
if err := json.Unmarshal([]byte(w.String()), &entry); err != nil {
t.Error(err)
}
assert.Equal(t, levelInfo, entry[levelKey])
assert.Equal(t, message, entry[contentKey])
assert.Equal(t, "1000.0ms", entry[durationKey])
}
func TestSetLevel(t *testing.T) {
SetLevel(ErrorLevel)
const message = "hello there"
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
Info(message)
assert.Equal(t, 0, w.builder.Len())
}
func TestSetLevelTwiceWithMode(t *testing.T) {
testModes := []string{
"console",
"volumn",
"mode",
}
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
for _, mode := range testModes {
testSetLevelTwiceWithMode(t, mode, w)
}
}
func TestSetLevelWithDuration(t *testing.T) {
SetLevel(ErrorLevel)
const message = "hello there"
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
WithDuration(time.Second).Info(message)
assert.Equal(t, 0, w.builder.Len())
}
func TestErrorfWithWrappedError(t *testing.T) {
SetLevel(ErrorLevel)
const message = "there"
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
Errorf("hello %s", errors.New(message))
assert.True(t, strings.Contains(w.String(), "hello there"))
}
func TestMustNil(t *testing.T) {
Must(nil)
}
func TestSetup(t *testing.T) {
defer func() {
SetLevel(InfoLevel)
atomic.StoreUint32(&encoding, jsonEncodingType)
}()
setupOnce = sync.Once{}
MustSetup(LogConf{
ServiceName: "any",
Mode: "console",
Encoding: "json",
TimeFormat: timeFormat,
})
setupOnce = sync.Once{}
MustSetup(LogConf{
ServiceName: "any",
Mode: "console",
TimeFormat: timeFormat,
})
setupOnce = sync.Once{}
MustSetup(LogConf{
ServiceName: "any",
Mode: "file",
Path: os.TempDir(),
})
setupOnce = sync.Once{}
MustSetup(LogConf{
ServiceName: "any",
Mode: "volume",
Path: os.TempDir(),
})
setupOnce = sync.Once{}
MustSetup(LogConf{
ServiceName: "any",
Mode: "console",
TimeFormat: timeFormat,
})
setupOnce = sync.Once{}
MustSetup(LogConf{
ServiceName: "any",
Mode: "console",
Encoding: plainEncoding,
})
defer os.RemoveAll("CD01CB7D-2705-4F3F-889E-86219BF56F10")
assert.NotNil(t, setupWithVolume(LogConf{}))
assert.Nil(t, setupWithVolume(LogConf{
ServiceName: "CD01CB7D-2705-4F3F-889E-86219BF56F10",
}))
assert.Nil(t, setupWithVolume(LogConf{
ServiceName: "CD01CB7D-2705-4F3F-889E-86219BF56F10",
Rotation: sizeRotationRule,
}))
assert.NotNil(t, setupWithFiles(LogConf{}))
assert.Nil(t, setupWithFiles(LogConf{
ServiceName: "any",
Path: os.TempDir(),
Compress: true,
KeepDays: 1,
MaxBackups: 3,
MaxSize: 1024 * 1024,
}))
setupLogLevel(LogConf{
Level: levelInfo,
})
setupLogLevel(LogConf{
Level: levelError,
})
setupLogLevel(LogConf{
Level: levelSevere,
})
_, err := createOutput("")
assert.NotNil(t, err)
Disable()
SetLevel(InfoLevel)
atomic.StoreUint32(&encoding, jsonEncodingType)
}
func TestDisable(t *testing.T) {
Disable()
defer func() {
SetLevel(InfoLevel)
atomic.StoreUint32(&encoding, jsonEncodingType)
}()
var opt logOptions
WithKeepDays(1)(&opt)
WithGzip()(&opt)
WithMaxBackups(1)(&opt)
WithMaxSize(1024)(&opt)
assert.Nil(t, Close())
assert.Nil(t, Close())
assert.Equal(t, uint32(disableLevel), atomic.LoadUint32(&logLevel))
}
func TestDisableStat(t *testing.T) {
DisableStat()
const message = "hello there"
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
Stat(message)
assert.Equal(t, 0, w.builder.Len())
}
func TestAddWriter(t *testing.T) {
const message = "hello there"
w := new(mockWriter)
AddWriter(w)
w1 := new(mockWriter)
AddWriter(w1)
Error(message)
assert.Contains(t, w.String(), message)
assert.Contains(t, w1.String(), message)
}
func TestSetWriter(t *testing.T) {
atomic.StoreUint32(&logLevel, 0)
Reset()
SetWriter(nopWriter{})
assert.NotNil(t, writer.Load())
assert.True(t, writer.Load() == nopWriter{})
mocked := new(mockWriter)
SetWriter(mocked)
assert.Equal(t, mocked, writer.Load())
}
func TestWithGzip(t *testing.T) {
fn := WithGzip()
var opt logOptions
fn(&opt)
assert.True(t, opt.gzipEnabled)
}
func TestWithKeepDays(t *testing.T) {
fn := WithKeepDays(1)
var opt logOptions
fn(&opt)
assert.Equal(t, 1, opt.keepDays)
}
func BenchmarkCopyByteSliceAppend(b *testing.B) {
for i := 0; i < b.N; i++ {
var buf []byte
buf = append(buf, getTimestamp()...)
buf = append(buf, ' ')
buf = append(buf, s...)
_ = buf
}
}
func BenchmarkCopyByteSliceAllocExactly(b *testing.B) {
for i := 0; i < b.N; i++ {
now := []byte(getTimestamp())
buf := make([]byte, len(now)+1+len(s))
n := copy(buf, now)
buf[n] = ' '
copy(buf[n+1:], s)
}
}
func BenchmarkCopyByteSlice(b *testing.B) {
var buf []byte
for i := 0; i < b.N; i++ {
buf = make([]byte, len(s))
copy(buf, s)
}
fmt.Fprint(io.Discard, buf)
}
func BenchmarkCopyOnWriteByteSlice(b *testing.B) {
var buf []byte
for i := 0; i < b.N; i++ {
size := len(s)
buf = s[:size:size]
}
fmt.Fprint(io.Discard, buf)
}
func BenchmarkCacheByteSlice(b *testing.B) {
for i := 0; i < b.N; i++ {
dup := fetch()
copy(dup, s)
put(dup)
}
}
func BenchmarkLogs(b *testing.B) {
b.ReportAllocs()
log.SetOutput(io.Discard)
for i := 0; i < b.N; i++ {
Info(i)
}
}
func fetch() []byte {
select {
case b := <-pool:
return b
default:
}
return make([]byte, 4096)
}
func getFileLine() (string, int) {
_, file, line, _ := runtime.Caller(1)
short := file
for i := len(file) - 1; i > 0; i-- {
if file[i] == '/' {
short = file[i+1:]
break
}
}
return short, line
}
func put(b []byte) {
select {
case pool <- b:
default:
}
}
func doTestStructedLog(t *testing.T, level string, w *mockWriter, write func(...any)) {
const message = "hello there"
write(message)
var entry map[string]any
if err := json.Unmarshal([]byte(w.String()), &entry); err != nil {
t.Error(err)
}
assert.Equal(t, level, entry[levelKey])
val, ok := entry[contentKey]
assert.True(t, ok)
assert.True(t, strings.Contains(val.(string), message))
}
func doTestStructedLogConsole(t *testing.T, w *mockWriter, write func(...any)) {
const message = "hello there"
write(message)
assert.True(t, strings.Contains(w.String(), message))
}
func testSetLevelTwiceWithMode(t *testing.T, mode string, w *mockWriter) {
writer.Store(nil)
_ = SetUp(LogConf{
Mode: mode,
Level: "debug",
Path: "/dev/null",
Encoding: plainEncoding,
Stat: false,
TimeFormat: time.RFC3339,
FileTimeFormat: time.DateTime,
})
_ = SetUp(LogConf{
Mode: mode,
Level: "info",
Path: "/dev/null",
})
const message = "hello there"
Info(message)
assert.Equal(t, 0, w.builder.Len())
Infof(message)
assert.Equal(t, 0, w.builder.Len())
ErrorStack(message)
assert.Equal(t, 0, w.builder.Len())
ErrorStackf(message)
assert.Equal(t, 0, w.builder.Len())
}
type ValStringer struct {
val string
}
func (v ValStringer) String() string {
return v.val
}
func validateFields(t *testing.T, content string, fields map[string]any) {
var m map[string]any
if err := json.Unmarshal([]byte(content), &m); err != nil {
t.Error(err)
}
for k, v := range fields {
if reflect.TypeOf(v).Kind() == reflect.Slice {
assert.EqualValues(t, v, m[k])
} else {
assert.Equal(t, v, m[k], content)
}
}
}
type nilError struct {
Name string
}
func (e *nilError) Error() string {
return e.Name
}
type nilStringer struct {
Name string
}
func (s *nilStringer) String() string {
return s.Name
}
type innerPanicStringer struct {
Inner *struct {
Name string
}
}
func (s innerPanicStringer) String() string {
return s.Inner.Name
}
type panicStringer struct {
}
func (s panicStringer) String() string {
panic("panic")
}
+84
View File
@@ -0,0 +1,84 @@
package logtest
import (
"bytes"
"encoding/json"
"io"
"testing"
"github.com/perfect-panel/ppanel-server/pkg/logger"
)
type Buffer struct {
buf *bytes.Buffer
t *testing.T
}
func Discard(t *testing.T) {
prev := logger.Reset()
logger.SetWriter(logger.NewWriter(io.Discard))
t.Cleanup(func() {
logger.SetWriter(prev)
})
}
func NewCollector(t *testing.T) *Buffer {
var buf bytes.Buffer
writer := logger.NewWriter(&buf)
prev := logger.Reset()
logger.SetWriter(writer)
t.Cleanup(func() {
logger.SetWriter(prev)
})
return &Buffer{
buf: &buf,
t: t,
}
}
func (b *Buffer) Bytes() []byte {
return b.buf.Bytes()
}
func (b *Buffer) Content() string {
var m map[string]interface{}
if err := json.Unmarshal(b.buf.Bytes(), &m); err != nil {
return ""
}
content, ok := m["content"]
if !ok {
return ""
}
switch val := content.(type) {
case string:
return val
default:
// err is impossible to be not nil, unmarshaled from b.buf.Bytes()
bs, _ := json.Marshal(content)
return string(bs)
}
}
func (b *Buffer) Reset() {
b.buf.Reset()
}
func (b *Buffer) String() string {
return b.buf.String()
}
func PanicOnFatal(t *testing.T) {
ok := logger.ExitOnFatal.CompareAndSwap(true, false)
if !ok {
return
}
t.Cleanup(func() {
logger.ExitOnFatal.CompareAndSwap(false, true)
})
}
+44
View File
@@ -0,0 +1,44 @@
package logtest
import (
"errors"
"testing"
"github.com/perfect-panel/ppanel-server/pkg/logger"
"github.com/stretchr/testify/assert"
)
func TestCollector(t *testing.T) {
const input = "hello"
c := NewCollector(t)
logger.Info(input)
assert.Equal(t, input, c.Content())
assert.Contains(t, c.String(), input)
c.Reset()
assert.Empty(t, c.Bytes())
}
func TestPanicOnFatal(t *testing.T) {
const input = "hello"
Discard(t)
logger.Info(input)
PanicOnFatal(t)
PanicOnFatal(t)
assert.Panics(t, func() {
logger.Must(errors.New("foo"))
})
}
func TestCollectorContent(t *testing.T) {
const input = "hello"
c := NewCollector(t)
c.buf.WriteString(input)
assert.Empty(t, c.Content())
c.Reset()
c.buf.WriteString(`{}`)
assert.Empty(t, c.Content())
c.Reset()
c.buf.WriteString(`{"content":1}`)
assert.Equal(t, "1", c.Content())
}
+22
View File
@@ -0,0 +1,22 @@
package logger
import "log"
type logWriter struct {
logger *log.Logger
}
func newLogWriter(logger *log.Logger) logWriter {
return logWriter{
logger: logger,
}
}
func (lw logWriter) Close() error {
return nil
}
func (lw logWriter) Write(data []byte) (int, error) {
lw.logger.Print(string(data))
return len(data), nil
}
+144
View File
@@ -0,0 +1,144 @@
## logger 配置
```go
type LogConf struct {
ServiceName string
Mode string
Encoding string
TimeFormat string
Path string
Level string
Compress bool
KeepDays int
StackCooldownMillis int
MaxBackups int
MaxSize int
Rotation string
}
```
- `ServiceName`:设置服务名称,可选。在 `volume` 模式下,该名称用于生成日志文件。
- `Mode`:输出日志的模式,默认是 `console`
- `console` 模式将日志写到 `stdout/stderr`
- `file` 模式将日志写到 `Path` 指定目录的文件中
- `volume` 模式在 docker 中使用,将日志写入挂载的卷中
- `Encoding`: 指示如何对日志进行编码,默认是 `json`
- `json`模式以 json 格式写日志
- `plain`模式用纯文本写日志,并带有终端颜色显示
- `TimeFormat`:自定义时间格式,可选。默认是 `2006-01-02T15:04:05.000Z07:00`
- `Path`:设置日志路径,默认为 `logs`
- `Level`: 用于过滤日志的日志级别。默认为 `info`
- `info`,所有日志都被写入
- `error`, `info` 的日志被丢弃
- `severe`, `info``error` 日志被丢弃,只有 `severe` 日志被写入
- `Compress`: 是否压缩日志文件,只在 `file` 模式下工作
- `KeepDays`:日志文件被保留多少天,在给定的天数之后,过期的文件将被自动删除。对 `console` 模式没有影响
- `StackCooldownMillis`:多少毫秒后再次写入堆栈跟踪。用来避免堆栈跟踪日志过多
- `MaxBackups`: 多少个日志文件备份将被保存。0代表所有备份都被保存。当`Rotation`被设置为`size`时才会起作用。注意:`KeepDays`选项的优先级会比`MaxBackups`高,即使`MaxBackups`被设置为0,当达到`KeepDays`上限时备份文件同样会被删除。
- `MaxSize`: 当前被写入的日志文件最大可占用多少空间。0代表没有上限。单位为`MB`。当`Rotation`被设置为`size`时才会起作用。
- `Rotation`: 日志轮转策略类型。默认为`daily`(按天轮转)。
- `daily` 按天轮转。
- `size` 按日志大小轮转。
## 打印日志方法
```go
type Logger interface {
// Error logs a message at error level.
Error(...any)
// Errorf logs a message at error level.
Errorf(string, ...any)
// Errorv logs a message at error level.
Errorv(any)
// Errorw logs a message at error level.
Errorw(string, ...LogField)
// Info logs a message at info level.
Info(...any)
// Infof logs a message at info level.
Infof(string, ...any)
// Infov logs a message at info level.
Infov(any)
// Infow logs a message at info level.
Infow(string, ...LogField)
// Slow logs a message at slow level.
Slow(...any)
// Slowf logs a message at slow level.
Slowf(string, ...any)
// Slowv logs a message at slow level.
Slowv(any)
// Sloww logs a message at slow level.
Sloww(string, ...LogField)
// WithContext returns a new logger with the given context.
WithContext(context.Context) Logger
// WithDuration returns a new logger with the given duration.
WithDuration(time.Duration) Logger
}
```
- `Error`, `Info`, `Slow`: 将任何类型的信息写进日志,使用 `fmt.Sprint(...)` 来转换为 `string`
- `Errorf`, `Infof`, `Slowf`: 将指定格式的信息写入日志
- `Errorv`, `Infov`, `Slowv`: 将任何类型的信息写入日志,用 `json marshal` 编码
- `Errorw`, `Infow`, `Sloww`: 写日志,并带上给定的 `key:value` 字段
- `WithContext`:将给定的 ctx 注入日志信息,例如用于记录 `trace-id``span-id`
- `WithDuration`: 将指定的时间写入日志信息中,字段名为 `duration`
## 将日志写到指定的存储
`logger`定义了两个接口,方便自定义 `logger`,将日志写入任何存储。
- `logger.NewWriter(w io.Writer)`
- `logger.SetWriter(write logger.Writer)`
## 过滤敏感字段
如果我们需要防止 `password` 字段被记录下来,我们可以像下面这样实现。
```go
type (
Message struct {
Name string
Password string
Message string
}
SensitiveLogger struct {
logger.Writer
}
)
func NewSensitiveLogger(writer logger.Writer) *SensitiveLogger {
return &SensitiveLogger{
Writer: writer,
}
}
func (l *SensitiveLogger) Info(msg any, fields ...logger.LogField) {
if m, ok := msg.(Message); ok {
l.Writer.Info(Message{
Name: m.Name,
Password: "******",
Message: m.Message,
}, fields...)
} else {
l.Writer.Info(msg, fields...)
}
}
func main() {
// setup logger to make sure originalWriter not nil,
// the injected writer is only for filtering, like a middleware.
originalWriter := logger.Reset()
writer := NewSensitiveLogger(originalWriter)
logger.SetWriter(writer)
logger.Infov(Message{
Name: "foo",
Password: "shouldNotAppear",
Message: "bar",
})
// more code
}
```
+144
View File
@@ -0,0 +1,144 @@
## logger configurations
```go
type LogConf struct {
ServiceName string
Mode string
Encoding string
TimeFormat string
Path string
Level string
Compress bool
KeepDays int
StackCooldownMillis int
MaxBackups int
MaxSize int
Rotation string
}
```
- `ServiceName`: set the service name, optional. on `volume` mode, the name is used to generate the log files. Within `rest/zrpc` services, the name will be set to the name of `rest` or `zrpc` automatically.
- `Mode`: the mode to output the logs, default is `console`.
- `console` mode writes the logs to `stdout/stderr`.
- `file` mode writes the logs to the files specified by `Path`.
- `volume` mode is used in docker, to write logs into mounted volumes.
- `Encoding`: indicates how to encode the logs, default is `json`.
- `json` mode writes the logs in json format.
- `plain` mode writes the logs with plain text, with terminal color enabled.
- `TimeFormat`: customize the time format, optional. Default is `2006-01-02T15:04:05.000Z07:00`.
- `Path`: set the log path, default to `logs`.
- `Level`: the logging level to filter logs. Default is `info`.
- `info`, all logs are written.
- `error`, `info` logs are suppressed.
- `severe`, `info` and `error` logs are suppressed, only `severe` logs are written.
- `Compress`: whether or not to compress log files, only works with `file` mode.
- `KeepDays`: how many days that the log files are kept, after the given days, the outdated files will be deleted automatically. It has no effect on `console` mode.
- `StackCooldownMillis`: how many milliseconds to rewrite stacktrace again. Its used to avoid stacktrace flooding.
- `MaxBackups`: represents how many backup log files will be kept. 0 means all files will be kept forever. Only take effect when `Rotation` is `size`. NOTE: the level of option `KeepDays` will be higher. Even though `MaxBackups` sets 0, log files will still be removed if the `KeepDays` limitation is reached.
- `MaxSize`: represents how much space the writing log file takes up. 0 means no limit. The unit is `MB`. Only take effect when `Rotation` is `size`.
- `Rotation`: represents the type of log rotation rule. Default is `daily`.
- `daily` rotate the logs by day.
- `size` rotate the logs by size of logs.
## Logging methods
```go
type Logger interface {
// Error logs a message at error level.
Error(...any)
// Errorf logs a message at error level.
Errorf(string, ...any)
// Errorv logs a message at error level.
Errorv(any)
// Errorw logs a message at error level.
Errorw(string, ...LogField)
// Info logs a message at info level.
Info(...any)
// Infof logs a message at info level.
Infof(string, ...any)
// Infov logs a message at info level.
Infov(any)
// Infow logs a message at info level.
Infow(string, ...LogField)
// Slow logs a message at slow level.
Slow(...any)
// Slowf logs a message at slow level.
Slowf(string, ...any)
// Slowv logs a message at slow level.
Slowv(any)
// Sloww logs a message at slow level.
Sloww(string, ...LogField)
// WithContext returns a new logger with the given context.
WithContext(context.Context) Logger
// WithDuration returns a new logger with the given duration.
WithDuration(time.Duration) Logger
}
```
- `Error`, `Info`, `Slow`: write any kind of messages into logs, with like `fmt.Sprint(…)`.
- `Errorf`, `Infof`, `Slowf`: write messages with given format into logs.
- `Errorv`, `Infov`, `Slowv`: write any kind of messages into logs, with json marshalling to encode them.
- `Errorw`, `Infow`, `Sloww`: write the string message with given `key:value` fields.
- `WithContext`: inject the given ctx into the log messages, typically used to log `trace-id` and `span-id`.
- `WithDuration`: write elapsed duration into the log messages, with key `duration`.
## Write the logs to specific stores
`logger` defined two interfaces to let you customize `logger` to write logs into any stores.
- `logger.NewWriter(w io.Writer)`
- `logger.SetWriter(writer logx.Writer)`
## Filtering sensitive fields
If we need to prevent the `password` fields from logging, we can do it like below:
```go
type (
Message struct {
Name string
Password string
Message string
}
SensitiveLogger struct {
logger.Writer
}
)
func NewSensitiveLogger(writer logger.Writer) *SensitiveLogger {
return &SensitiveLogger{
Writer: writer,
}
}
func (l *SensitiveLogger) Info(msg any, fields ...logx.LogField) {
if m, ok := msg.(Message); ok {
l.Writer.Info(Message{
Name: m.Name,
Password: "******",
Message: m.Message,
}, fields...)
} else {
l.Writer.Info(msg, fields...)
}
}
func main() {
// setup logx to make sure originalWriter not nil,
// the injected writer is only for filtering, like a middleware.
originalWriter := logger.Reset()
writer := NewSensitiveLogger(originalWriter)
logger.SetWriter(writer)
logger.Infov(Message{
Name: "foo",
Password: "shouldNotAppear",
Message: "bar",
})
// more code
}
```
+234
View File
@@ -0,0 +1,234 @@
package logger
import (
"context"
"fmt"
"time"
"github.com/perfect-panel/ppanel-server/internal/trace"
"github.com/perfect-panel/ppanel-server/pkg/timex"
)
// WithCallerSkip returns a Logger with given caller skip.
func WithCallerSkip(skip int) Logger {
if skip <= 0 {
return new(richLogger)
}
return &richLogger{
callerSkip: skip,
}
}
// WithContext sets ctx to log, for keeping tracing information.
func WithContext(ctx context.Context) Logger {
return &richLogger{
ctx: ctx,
}
}
// WithDuration returns a Logger with given duration.
func WithDuration(d time.Duration) Logger {
return &richLogger{
fields: []LogField{Field(durationKey, timex.ReprOfDuration(d))},
}
}
type richLogger struct {
ctx context.Context
callerSkip int
fields []LogField
}
func (l *richLogger) Debug(v ...any) {
if shallLog(DebugLevel) {
l.debug(fmt.Sprint(v...))
}
}
func (l *richLogger) Debugf(format string, v ...any) {
if shallLog(DebugLevel) {
l.debug(fmt.Sprintf(format, v...))
}
}
func (l *richLogger) Debugv(v any) {
if shallLog(DebugLevel) {
l.debug(v)
}
}
func (l *richLogger) Debugw(msg string, fields ...LogField) {
if shallLog(DebugLevel) {
l.debug(msg, fields...)
}
}
func (l *richLogger) Error(v ...any) {
if shallLog(ErrorLevel) {
l.err(fmt.Sprint(v...))
}
}
func (l *richLogger) Errorf(format string, v ...any) {
if shallLog(ErrorLevel) {
l.err(fmt.Sprintf(format, v...))
}
}
func (l *richLogger) Errorv(v any) {
if shallLog(ErrorLevel) {
l.err(v)
}
}
func (l *richLogger) Errorw(msg string, fields ...LogField) {
if shallLog(ErrorLevel) {
l.err(msg, fields...)
}
}
func (l *richLogger) Info(v ...any) {
if shallLog(InfoLevel) {
l.info(fmt.Sprint(v...))
}
}
func (l *richLogger) Infof(format string, v ...any) {
if shallLog(InfoLevel) {
l.info(fmt.Sprintf(format, v...))
}
}
func (l *richLogger) Infov(v any) {
if shallLog(InfoLevel) {
l.info(v)
}
}
func (l *richLogger) Infow(msg string, fields ...LogField) {
if shallLog(InfoLevel) {
l.info(msg, fields...)
}
}
func (l *richLogger) Slow(v ...any) {
if shallLog(ErrorLevel) {
l.slow(fmt.Sprint(v...))
}
}
func (l *richLogger) Slowf(format string, v ...any) {
if shallLog(ErrorLevel) {
l.slow(fmt.Sprintf(format, v...))
}
}
func (l *richLogger) Slowv(v any) {
if shallLog(ErrorLevel) {
l.slow(v)
}
}
func (l *richLogger) Sloww(msg string, fields ...LogField) {
if shallLog(ErrorLevel) {
l.slow(msg, fields...)
}
}
func (l *richLogger) WithCallerSkip(skip int) Logger {
if skip <= 0 {
return l
}
return &richLogger{
ctx: l.ctx,
callerSkip: skip,
fields: l.fields,
}
}
func (l *richLogger) WithContext(ctx context.Context) Logger {
return &richLogger{
ctx: ctx,
callerSkip: l.callerSkip,
fields: l.fields,
}
}
func (l *richLogger) WithDuration(duration time.Duration) Logger {
fields := append(l.fields, Field(durationKey, timex.ReprOfDuration(duration)))
return &richLogger{
ctx: l.ctx,
callerSkip: l.callerSkip,
fields: fields,
}
}
func (l *richLogger) WithFields(fields ...LogField) Logger {
if len(fields) == 0 {
return l
}
f := append(l.fields, fields...)
return &richLogger{
ctx: l.ctx,
callerSkip: l.callerSkip,
fields: f,
}
}
func (l *richLogger) buildFields(fields ...LogField) []LogField {
fields = append(l.fields, fields...)
fields = append(fields, Field(callerKey, getCaller(callerDepth+l.callerSkip)))
if l.ctx == nil {
return fields
}
traceID := trace.TraceIDFromContext(l.ctx)
if len(traceID) > 0 {
fields = append(fields, Field(traceKey, traceID))
}
spanID := trace.SpanIDFromContext(l.ctx)
if len(spanID) > 0 {
fields = append(fields, Field(spanKey, spanID))
}
val := l.ctx.Value(fieldsContextKey)
if val != nil {
if arr, ok := val.([]LogField); ok {
fields = append(fields, arr...)
}
}
return fields
}
func (l *richLogger) debug(v any, fields ...LogField) {
if shallLog(DebugLevel) {
getWriter().Debug(v, l.buildFields(fields...)...)
}
}
func (l *richLogger) err(v any, fields ...LogField) {
if shallLog(ErrorLevel) {
getWriter().Error(v, l.buildFields(fields...)...)
}
}
func (l *richLogger) info(v any, fields ...LogField) {
if shallLog(InfoLevel) {
getWriter().Info(v, l.buildFields(fields...)...)
}
}
func (l *richLogger) slow(v any, fields ...LogField) {
if shallLog(ErrorLevel) {
getWriter().Slow(v, l.buildFields(fields...)...)
}
}
+408
View File
@@ -0,0 +1,408 @@
package logger
import (
"context"
"encoding/json"
"fmt"
"io"
"strings"
"sync/atomic"
"testing"
"time"
"github.com/stretchr/testify/assert"
"go.opentelemetry.io/otel"
sdktrace "go.opentelemetry.io/otel/sdk/trace"
)
func TestTraceLog(t *testing.T) {
SetLevel(InfoLevel)
w := new(mockWriter)
old := writer.Swap(w)
writer.lock.RLock()
defer func() {
writer.lock.RUnlock()
writer.Store(old)
}()
otp := otel.GetTracerProvider()
tp := sdktrace.NewTracerProvider(sdktrace.WithSampler(sdktrace.AlwaysSample()))
otel.SetTracerProvider(tp)
defer otel.SetTracerProvider(otp)
ctx, span := tp.Tracer("trace-id").Start(context.Background(), "span-id")
defer span.End()
WithContext(ctx).Info(testlog)
validate(t, w.String(), true, true)
}
func TestTraceDebug(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
writer.lock.RLock()
defer func() {
writer.lock.RUnlock()
writer.Store(old)
}()
otp := otel.GetTracerProvider()
tp := sdktrace.NewTracerProvider(sdktrace.WithSampler(sdktrace.AlwaysSample()))
otel.SetTracerProvider(tp)
defer otel.SetTracerProvider(otp)
ctx, span := tp.Tracer("foo").Start(context.Background(), "bar")
defer span.End()
l := WithContext(ctx)
SetLevel(DebugLevel)
l.WithDuration(time.Second).Debug(testlog)
assert.True(t, strings.Contains(w.String(), traceKey))
assert.True(t, strings.Contains(w.String(), spanKey))
w.Reset()
l.WithDuration(time.Second).Debugf(testlog)
validate(t, w.String(), true, true)
w.Reset()
l.WithDuration(time.Second).Debugv(testlog)
validate(t, w.String(), true, true)
w.Reset()
l.WithDuration(time.Second).Debugv(testobj)
validateContentType(t, w.String(), map[string]any{}, true, true)
w.Reset()
l.WithDuration(time.Second).Debugw(testlog, Field("foo", "bar"))
validate(t, w.String(), true, true)
assert.True(t, strings.Contains(w.String(), "foo"), w.String())
assert.True(t, strings.Contains(w.String(), "bar"), w.String())
}
func TestTraceError(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
writer.lock.RLock()
defer func() {
writer.lock.RUnlock()
writer.Store(old)
}()
otp := otel.GetTracerProvider()
tp := sdktrace.NewTracerProvider(sdktrace.WithSampler(sdktrace.AlwaysSample()))
otel.SetTracerProvider(tp)
defer otel.SetTracerProvider(otp)
ctx, span := tp.Tracer("trace-id").Start(context.Background(), "span-id")
defer span.End()
var nilCtx context.Context
l := WithContext(context.Background())
l = l.WithContext(nilCtx)
l = l.WithContext(ctx)
SetLevel(ErrorLevel)
l.WithDuration(time.Second).Error(testlog)
validate(t, w.String(), true, true)
w.Reset()
l.WithDuration(time.Second).Errorf(testlog)
validate(t, w.String(), true, true)
w.Reset()
l.WithDuration(time.Second).Errorv(testlog)
validate(t, w.String(), true, true)
w.Reset()
l.WithDuration(time.Second).Errorv(testobj)
validateContentType(t, w.String(), map[string]any{}, true, true)
w.Reset()
l.WithDuration(time.Second).Errorw(testlog, Field("basket", "ball"))
validate(t, w.String(), true, true)
assert.True(t, strings.Contains(w.String(), "basket"), w.String())
assert.True(t, strings.Contains(w.String(), "ball"), w.String())
}
func TestTraceInfo(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
writer.lock.RLock()
defer func() {
writer.lock.RUnlock()
writer.Store(old)
}()
otp := otel.GetTracerProvider()
tp := sdktrace.NewTracerProvider(sdktrace.WithSampler(sdktrace.AlwaysSample()))
otel.SetTracerProvider(tp)
defer otel.SetTracerProvider(otp)
ctx, span := tp.Tracer("trace-id").Start(context.Background(), "span-id")
defer span.End()
SetLevel(InfoLevel)
l := WithContext(ctx)
l.WithDuration(time.Second).Info(testlog)
validate(t, w.String(), true, true)
w.Reset()
l.WithDuration(time.Second).Infof(testlog)
validate(t, w.String(), true, true)
w.Reset()
l.WithDuration(time.Second).Infov(testlog)
validate(t, w.String(), true, true)
w.Reset()
l.WithDuration(time.Second).Infov(testobj)
validateContentType(t, w.String(), map[string]any{}, true, true)
w.Reset()
l.WithDuration(time.Second).Infow(testlog, Field("basket", "ball"))
validate(t, w.String(), true, true)
assert.True(t, strings.Contains(w.String(), "basket"), w.String())
assert.True(t, strings.Contains(w.String(), "ball"), w.String())
}
func TestTraceInfoConsole(t *testing.T) {
old := atomic.SwapUint32(&encoding, jsonEncodingType)
defer atomic.StoreUint32(&encoding, old)
w := new(mockWriter)
o := writer.Swap(w)
writer.lock.RLock()
defer func() {
writer.lock.RUnlock()
writer.Store(o)
}()
otp := otel.GetTracerProvider()
tp := sdktrace.NewTracerProvider(sdktrace.WithSampler(sdktrace.AlwaysSample()))
otel.SetTracerProvider(tp)
defer otel.SetTracerProvider(otp)
ctx, span := tp.Tracer("trace-id").Start(context.Background(), "span-id")
defer span.End()
l := WithContext(ctx)
SetLevel(InfoLevel)
l.WithDuration(time.Second).Info(testlog)
validate(t, w.String(), true, true)
w.Reset()
l.WithDuration(time.Second).Infof(testlog)
validate(t, w.String(), true, true)
w.Reset()
l.WithDuration(time.Second).Infov(testlog)
validate(t, w.String(), true, true)
w.Reset()
l.WithDuration(time.Second).Infov(testobj)
validateContentType(t, w.String(), map[string]any{}, true, true)
}
func TestTraceSlow(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
writer.lock.RLock()
defer func() {
writer.lock.RUnlock()
writer.Store(old)
}()
otp := otel.GetTracerProvider()
tp := sdktrace.NewTracerProvider(sdktrace.WithSampler(sdktrace.AlwaysSample()))
otel.SetTracerProvider(tp)
defer otel.SetTracerProvider(otp)
ctx, span := tp.Tracer("trace-id").Start(context.Background(), "span-id")
defer span.End()
l := WithContext(ctx)
SetLevel(InfoLevel)
l.WithDuration(time.Second).Slow(testlog)
assert.True(t, strings.Contains(w.String(), traceKey))
assert.True(t, strings.Contains(w.String(), spanKey))
w.Reset()
l.WithDuration(time.Second).Slowf(testlog)
validate(t, w.String(), true, true)
w.Reset()
l.WithDuration(time.Second).Slowv(testlog)
validate(t, w.String(), true, true)
w.Reset()
l.WithDuration(time.Second).Slowv(testobj)
validateContentType(t, w.String(), map[string]any{}, true, true)
w.Reset()
l.WithDuration(time.Second).Sloww(testlog, Field("basket", "ball"))
validate(t, w.String(), true, true)
assert.True(t, strings.Contains(w.String(), "basket"), w.String())
assert.True(t, strings.Contains(w.String(), "ball"), w.String())
}
func TestTraceWithoutContext(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
writer.lock.RLock()
defer func() {
writer.lock.RUnlock()
writer.Store(old)
}()
l := WithContext(context.Background())
SetLevel(InfoLevel)
l.WithDuration(time.Second).Info(testlog)
validate(t, w.String(), false, false)
w.Reset()
l.WithDuration(time.Second).Infof(testlog)
validate(t, w.String(), false, false)
}
func TestLogWithFields(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
writer.lock.RLock()
defer func() {
writer.lock.RUnlock()
writer.Store(old)
}()
ctx := ContextWithFields(context.Background(), Field("foo", "bar"))
l := WithContext(ctx)
SetLevel(InfoLevel)
l.Infow(testlog)
var val mockValue
assert.Nil(t, json.Unmarshal([]byte(w.String()), &val))
assert.Equal(t, "bar", val.Foo)
}
func TestLogWithCallerSkip(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
writer.lock.RLock()
defer func() {
writer.lock.RUnlock()
writer.Store(old)
}()
l := WithCallerSkip(1).WithCallerSkip(0)
p := func(v string) {
l.Infow(v)
}
file, line := getFileLine()
p(testlog)
assert.True(t, w.Contains(fmt.Sprintf("%s:%d", file, line+1)))
w.Reset()
l = WithCallerSkip(0).WithCallerSkip(1)
file, line = getFileLine()
p(testlog)
assert.True(t, w.Contains(fmt.Sprintf("%s:%d", file, line+1)))
}
func TestLogWithCallerSkipCopy(t *testing.T) {
log1 := WithCallerSkip(2)
log2 := log1.WithCallerSkip(3)
log3 := log2.WithCallerSkip(-1)
assert.Equal(t, 2, log1.(*richLogger).callerSkip)
assert.Equal(t, 3, log2.(*richLogger).callerSkip)
assert.Equal(t, 3, log3.(*richLogger).callerSkip)
}
func TestLogWithContextCopy(t *testing.T) {
c1 := context.Background()
type ctxKey string // 定义新的字符串类型
const fooKey ctxKey = "foo" // 使用这个 key
c2 := context.WithValue(context.Background(), fooKey, "bar")
log1 := WithContext(c1)
log2 := log1.WithContext(c2)
assert.Equal(t, c1, log1.(*richLogger).ctx)
assert.Equal(t, c2, log2.(*richLogger).ctx)
}
func TestLogWithDurationCopy(t *testing.T) {
log1 := WithContext(context.Background())
log2 := log1.WithDuration(time.Second)
assert.Empty(t, log1.(*richLogger).fields)
assert.Equal(t, 1, len(log2.(*richLogger).fields))
var w mockWriter
old := writer.Swap(&w)
defer writer.Store(old)
log2.Info("hello")
assert.Contains(t, w.String(), `"duration":"1000.0ms"`)
}
func TestLogWithFieldsCopy(t *testing.T) {
log1 := WithContext(context.Background())
log2 := log1.WithFields(Field("foo", "bar"))
log3 := log1.WithFields()
assert.Empty(t, log1.(*richLogger).fields)
assert.Equal(t, 1, len(log2.(*richLogger).fields))
assert.Equal(t, log1, log3)
assert.Empty(t, log3.(*richLogger).fields)
var w mockWriter
old := writer.Swap(&w)
defer writer.Store(old)
log2.Info("hello")
assert.Contains(t, w.String(), `"foo":"bar"`)
}
func TestLoggerWithFields(t *testing.T) {
w := new(mockWriter)
old := writer.Swap(w)
writer.lock.RLock()
defer func() {
writer.lock.RUnlock()
writer.Store(old)
}()
l := WithContext(context.Background()).WithFields(Field("foo", "bar"))
l.Infow(testlog)
var val mockValue
assert.Nil(t, json.Unmarshal([]byte(w.String()), &val))
assert.Equal(t, "bar", val.Foo)
}
func validate(t *testing.T, body string, expectedTrace, expectedSpan bool) {
var val mockValue
dec := json.NewDecoder(strings.NewReader(body))
for {
var doc mockValue
err := dec.Decode(&doc)
if err == io.EOF {
// all done
break
}
if err != nil {
continue
}
val = doc
}
assert.Equal(t, expectedTrace, len(val.Trace) > 0, body)
assert.Equal(t, expectedSpan, len(val.Span) > 0, body)
}
func validateContentType(t *testing.T, body string, expectedType any, expectedTrace, expectedSpan bool) {
var val mockValue
dec := json.NewDecoder(strings.NewReader(body))
for {
var doc mockValue
err := dec.Decode(&doc)
if err == io.EOF {
// all done
break
}
if err != nil {
continue
}
val = doc
}
assert.IsType(t, expectedType, val.Content, body)
assert.Equal(t, expectedTrace, len(val.Trace) > 0, body)
assert.Equal(t, expectedSpan, len(val.Span) > 0, body)
}
type mockValue struct {
Trace string `json:"trace"`
Span string `json:"span"`
Foo string `json:"foo"`
Content any `json:"content"`
}
+468
View File
@@ -0,0 +1,468 @@
package logger
import (
"compress/gzip"
"errors"
"fmt"
"log"
"os"
"path"
"path/filepath"
"sort"
"strings"
"sync"
"time"
"github.com/perfect-panel/ppanel-server/pkg/fs"
"github.com/perfect-panel/ppanel-server/pkg/lang"
)
const (
dateFormat = "2006-01-02"
hoursPerDay = 24
bufferSize = 100
defaultDirMode = 0o755
defaultFileMode = 0o600
gzipExt = ".gz"
megaBytes = 1 << 20
)
var (
// ErrLogFileClosed is an error that indicates the log file is already closed.
ErrLogFileClosed = errors.New("error: log file closed")
fileTimeFormat = time.RFC3339
)
type (
// A RotateRule interface is used to define the log rotating rules.
RotateRule interface {
BackupFileName() string
MarkRotated()
OutdatedFiles() []string
ShallRotate(size int64) bool
}
// A RotateLogger is a Logger that can rotate log files with given rules.
RotateLogger struct {
filename string
backup string
fp *os.File
channel chan []byte
done chan lang.PlaceholderType
rule RotateRule
compress bool
// can't use threading.RoutineGroup because of cycle import
waitGroup sync.WaitGroup
closeOnce sync.Once
currentSize int64
}
// A DailyRotateRule is a rule to daily rotate the log files.
DailyRotateRule struct {
rotatedTime string
filename string
delimiter string
days int
gzip bool
}
// SizeLimitRotateRule a rotation rule that make the log file rotated base on size
SizeLimitRotateRule struct {
DailyRotateRule
maxSize int64
maxBackups int
}
)
// DefaultRotateRule is a default log rotating rule, currently DailyRotateRule.
func DefaultRotateRule(filename, delimiter string, days int, gzip bool) RotateRule {
return &DailyRotateRule{
rotatedTime: getNowDate(),
filename: filename,
delimiter: delimiter,
days: days,
gzip: gzip,
}
}
// BackupFileName returns the backup filename on rotating.
func (r *DailyRotateRule) BackupFileName() string {
return fmt.Sprintf("%s%s%s", r.filename, r.delimiter, getNowDate())
}
// MarkRotated marks the rotated time of r to be the current time.
func (r *DailyRotateRule) MarkRotated() {
r.rotatedTime = getNowDate()
}
// OutdatedFiles returns the files that exceeded the keeping days.
func (r *DailyRotateRule) OutdatedFiles() []string {
if r.days <= 0 {
return nil
}
var pattern string
if r.gzip {
pattern = fmt.Sprintf("%s%s*%s", r.filename, r.delimiter, gzipExt)
} else {
pattern = fmt.Sprintf("%s%s*", r.filename, r.delimiter)
}
files, err := filepath.Glob(pattern)
if err != nil {
Errorf("failed to delete outdated log files, error: %s", err)
return nil
}
var buf strings.Builder
boundary := time.Now().Add(-time.Hour * time.Duration(hoursPerDay*r.days)).Format(dateFormat)
buf.WriteString(r.filename)
buf.WriteString(r.delimiter)
buf.WriteString(boundary)
if r.gzip {
buf.WriteString(gzipExt)
}
boundaryFile := buf.String()
var outdates []string
for _, file := range files {
if file < boundaryFile {
outdates = append(outdates, file)
}
}
return outdates
}
// ShallRotate checks if the file should be rotated.
func (r *DailyRotateRule) ShallRotate(_ int64) bool {
return len(r.rotatedTime) > 0 && getNowDate() != r.rotatedTime
}
// NewSizeLimitRotateRule returns the rotation rule with size limit
func NewSizeLimitRotateRule(filename, delimiter string, days, maxSize, maxBackups int, gzip bool) RotateRule {
return &SizeLimitRotateRule{
DailyRotateRule: DailyRotateRule{
rotatedTime: getNowDateInRFC3339Format(),
filename: filename,
delimiter: delimiter,
days: days,
gzip: gzip,
},
maxSize: int64(maxSize) * megaBytes,
maxBackups: maxBackups,
}
}
func (r *SizeLimitRotateRule) BackupFileName() string {
dir := filepath.Dir(r.filename)
prefix, ext := r.parseFilename()
timestamp := getNowDateInRFC3339Format()
return filepath.Join(dir, fmt.Sprintf("%s%s%s%s", prefix, r.delimiter, timestamp, ext))
}
func (r *SizeLimitRotateRule) MarkRotated() {
r.rotatedTime = getNowDateInRFC3339Format()
}
func (r *SizeLimitRotateRule) OutdatedFiles() []string {
dir := filepath.Dir(r.filename)
prefix, ext := r.parseFilename()
var pattern string
if r.gzip {
pattern = fmt.Sprintf("%s%s%s%s*%s%s", dir, string(filepath.Separator),
prefix, r.delimiter, ext, gzipExt)
} else {
pattern = fmt.Sprintf("%s%s%s%s*%s", dir, string(filepath.Separator),
prefix, r.delimiter, ext)
}
files, err := filepath.Glob(pattern)
if err != nil {
Errorf("failed to delete outdated log files, error: %s", err)
return nil
}
sort.Strings(files)
outdated := make(map[string]lang.PlaceholderType)
// test if too many backups
if r.maxBackups > 0 && len(files) > r.maxBackups {
for _, f := range files[:len(files)-r.maxBackups] {
outdated[f] = lang.Placeholder
}
files = files[len(files)-r.maxBackups:]
}
// test if any too old backups
if r.days > 0 {
boundary := time.Now().Add(-time.Hour * time.Duration(hoursPerDay*r.days)).Format(fileTimeFormat)
boundaryFile := filepath.Join(dir, fmt.Sprintf("%s%s%s%s", prefix, r.delimiter, boundary, ext))
if r.gzip {
boundaryFile += gzipExt
}
for _, f := range files {
if f >= boundaryFile {
break
}
outdated[f] = lang.Placeholder
}
}
var result []string
for k := range outdated {
result = append(result, k)
}
return result
}
func (r *SizeLimitRotateRule) ShallRotate(size int64) bool {
return r.maxSize > 0 && r.maxSize < size
}
func (r *SizeLimitRotateRule) parseFilename() (prefix, ext string) {
logName := filepath.Base(r.filename)
ext = filepath.Ext(r.filename)
prefix = logName[:len(logName)-len(ext)]
return
}
// NewLogger returns a RotateLogger with given filename and rule, etc.
func NewLogger(filename string, rule RotateRule, compress bool) (*RotateLogger, error) {
l := &RotateLogger{
filename: filename,
channel: make(chan []byte, bufferSize),
done: make(chan lang.PlaceholderType),
rule: rule,
compress: compress,
}
if err := l.initialize(); err != nil {
return nil, err
}
l.startWorker()
return l, nil
}
// Close closes l.
func (l *RotateLogger) Close() error {
var err error
l.closeOnce.Do(func() {
close(l.done)
l.waitGroup.Wait()
if err = l.fp.Sync(); err != nil {
return
}
err = l.fp.Close()
})
return err
}
func (l *RotateLogger) Write(data []byte) (int, error) {
select {
case l.channel <- data:
return len(data), nil
case <-l.done:
log.Println(string(data))
return 0, ErrLogFileClosed
}
}
func (l *RotateLogger) getBackupFilename() string {
if len(l.backup) == 0 {
return l.rule.BackupFileName()
}
return l.backup
}
func (l *RotateLogger) initialize() error {
l.backup = l.rule.BackupFileName()
if fileInfo, err := os.Stat(l.filename); err != nil {
basePath := path.Dir(l.filename)
if _, err = os.Stat(basePath); err != nil {
if err = os.MkdirAll(basePath, defaultDirMode); err != nil {
return err
}
}
if l.fp, err = os.Create(l.filename); err != nil {
return err
}
} else {
if l.fp, err = os.OpenFile(l.filename, os.O_APPEND|os.O_WRONLY, defaultFileMode); err != nil {
return err
}
l.currentSize = fileInfo.Size()
}
fs.CloseOnExec(l.fp)
return nil
}
func (l *RotateLogger) maybeCompressFile(file string) {
if !l.compress {
return
}
defer func() {
if r := recover(); r != nil {
ErrorStack(r)
}
}()
if _, err := os.Stat(file); err != nil {
// file doesn't exist or another error, ignore compression
return
}
compressLogFile(file)
}
func (l *RotateLogger) maybeDeleteOutdatedFiles() {
files := l.rule.OutdatedFiles()
for _, file := range files {
if err := os.Remove(file); err != nil {
Errorf("failed to remove outdated file: %s", file)
}
}
}
func (l *RotateLogger) postRotate(file string) {
go func() {
// we cannot use threading.GoSafe here, because of import cycle.
l.maybeCompressFile(file)
l.maybeDeleteOutdatedFiles()
}()
}
func (l *RotateLogger) rotate() error {
if l.fp != nil {
err := l.fp.Close()
l.fp = nil
if err != nil {
return err
}
}
_, err := os.Stat(l.filename)
if err == nil && len(l.backup) > 0 {
backupFilename := l.getBackupFilename()
err = os.Rename(l.filename, backupFilename)
if err != nil {
return err
}
l.postRotate(backupFilename)
}
l.backup = l.rule.BackupFileName()
if l.fp, err = os.Create(l.filename); err == nil {
fs.CloseOnExec(l.fp)
}
return err
}
func (l *RotateLogger) startWorker() {
l.waitGroup.Add(1)
go func() {
defer l.waitGroup.Done()
for {
select {
case event := <-l.channel:
l.write(event)
case <-l.done:
// avoid losing logs before closing.
for {
select {
case event := <-l.channel:
l.write(event)
default:
return
}
}
}
}
}()
}
func (l *RotateLogger) write(v []byte) {
if l.rule.ShallRotate(l.currentSize + int64(len(v))) {
if err := l.rotate(); err != nil {
log.Println(err)
} else {
l.rule.MarkRotated()
l.currentSize = 0
}
}
if l.fp != nil {
_, _ = l.fp.Write(v)
l.currentSize += int64(len(v))
}
}
func compressLogFile(file string) {
start := time.Now()
Infof("compressing log file: %s", file)
if err := gzipFile(file, fileSys); err != nil {
Errorf("compress error: %s", err)
} else {
Infof("compressed log file: %s, took %s", file, time.Since(start))
}
}
func getNowDate() string {
return time.Now().Format(dateFormat)
}
func getNowDateInRFC3339Format() string {
return time.Now().Format(fileTimeFormat)
}
func gzipFile(file string, fsys fileSystem) (err error) {
in, err := fsys.Open(file)
if err != nil {
return err
}
defer func() {
if e := fsys.Close(in); e != nil {
Errorf("failed to close file: %s, error: %v", file, e)
}
if err == nil {
// only remove the original file when compression is successful
err = fsys.Remove(file)
}
}()
out, err := fsys.Create(fmt.Sprintf("%s%s", file, gzipExt))
if err != nil {
return err
}
defer func() {
e := fsys.Close(out)
if err == nil {
err = e
}
}()
w := gzip.NewWriter(out)
if _, err = fsys.Copy(w, in); err != nil {
// failed to copy, no need to close w
return err
}
return fsys.Close(w)
}
+636
View File
@@ -0,0 +1,636 @@
package logger
import (
"errors"
"io"
"os"
"path"
"path/filepath"
"sync/atomic"
"syscall"
"testing"
"time"
"github.com/perfect-panel/ppanel-server/pkg/random"
"github.com/perfect-panel/ppanel-server/pkg/fs"
"github.com/stretchr/testify/assert"
)
func TestDailyRotateRuleMarkRotated(t *testing.T) {
t.Run("daily rule", func(t *testing.T) {
var rule DailyRotateRule
rule.MarkRotated()
assert.Equal(t, getNowDate(), rule.rotatedTime)
})
t.Run("daily rule", func(t *testing.T) {
rule := DefaultRotateRule("test", "-", 1, false)
_, ok := rule.(*DailyRotateRule)
assert.True(t, ok)
})
}
func TestDailyRotateRuleOutdatedFiles(t *testing.T) {
t.Run("no files", func(t *testing.T) {
var rule DailyRotateRule
assert.Empty(t, rule.OutdatedFiles())
rule.days = 1
assert.Empty(t, rule.OutdatedFiles())
rule.gzip = true
assert.Empty(t, rule.OutdatedFiles())
})
t.Run("bad files", func(t *testing.T) {
rule := DailyRotateRule{
filename: "[a-z",
}
assert.Empty(t, rule.OutdatedFiles())
rule.days = 1
assert.Empty(t, rule.OutdatedFiles())
rule.gzip = true
assert.Empty(t, rule.OutdatedFiles())
})
t.Run("temp files", func(t *testing.T) {
boundary := time.Now().Add(-time.Hour * time.Duration(hoursPerDay) * 2).Format(dateFormat)
f1, err := os.CreateTemp(os.TempDir(), "go-zero-test-"+boundary)
assert.NoError(t, err)
_ = f1.Close()
f2, err := os.CreateTemp(os.TempDir(), "go-zero-test-"+boundary)
assert.NoError(t, err)
_ = f2.Close()
t.Cleanup(func() {
_ = os.Remove(f1.Name())
_ = os.Remove(f2.Name())
})
rule := DailyRotateRule{
filename: path.Join(os.TempDir(), "go-zero-test-"),
days: 1,
}
assert.NotEmpty(t, rule.OutdatedFiles())
})
}
func TestDailyRotateRuleShallRotate(t *testing.T) {
var rule DailyRotateRule
rule.rotatedTime = time.Now().Add(time.Hour * 24).Format(dateFormat)
assert.True(t, rule.ShallRotate(0))
}
func TestSizeLimitRotateRuleMarkRotated(t *testing.T) {
t.Run("size limit rule", func(t *testing.T) {
var rule SizeLimitRotateRule
rule.MarkRotated()
assert.Equal(t, getNowDateInRFC3339Format(), rule.rotatedTime)
})
t.Run("size limit rule", func(t *testing.T) {
rule := NewSizeLimitRotateRule("foo", "-", 1, 1, 1, false)
rule.MarkRotated()
assert.Equal(t, getNowDateInRFC3339Format(), rule.(*SizeLimitRotateRule).rotatedTime)
})
}
func TestSizeLimitRotateRuleOutdatedFiles(t *testing.T) {
t.Run("no files", func(t *testing.T) {
var rule SizeLimitRotateRule
assert.Empty(t, rule.OutdatedFiles())
rule.days = 1
assert.Empty(t, rule.OutdatedFiles())
rule.gzip = true
assert.Empty(t, rule.OutdatedFiles())
rule.maxBackups = 0
assert.Empty(t, rule.OutdatedFiles())
})
t.Run("bad files", func(t *testing.T) {
rule := SizeLimitRotateRule{
DailyRotateRule: DailyRotateRule{
filename: "[a-z",
},
}
assert.Empty(t, rule.OutdatedFiles())
rule.days = 1
assert.Empty(t, rule.OutdatedFiles())
rule.gzip = true
assert.Empty(t, rule.OutdatedFiles())
})
t.Run("temp files", func(t *testing.T) {
boundary := time.Now().Add(-time.Hour * time.Duration(hoursPerDay) * 2).Format(dateFormat)
f1, err := os.CreateTemp(os.TempDir(), "go-zero-test-"+boundary)
assert.NoError(t, err)
f2, err := os.CreateTemp(os.TempDir(), "go-zero-test-"+boundary)
assert.NoError(t, err)
boundary1 := time.Now().Add(time.Hour * time.Duration(hoursPerDay) * 2).Format(dateFormat)
f3, err := os.CreateTemp(os.TempDir(), "go-zero-test-"+boundary1)
assert.NoError(t, err)
t.Cleanup(func() {
_ = f1.Close()
_ = os.Remove(f1.Name())
_ = f2.Close()
_ = os.Remove(f2.Name())
_ = f3.Close()
_ = os.Remove(f3.Name())
})
rule := SizeLimitRotateRule{
DailyRotateRule: DailyRotateRule{
filename: path.Join(os.TempDir(), "go-zero-test-"),
days: 1,
},
maxBackups: 3,
}
assert.NotEmpty(t, rule.OutdatedFiles())
})
t.Run("no backups", func(t *testing.T) {
boundary := time.Now().Add(-time.Hour * time.Duration(hoursPerDay) * 2).Format(dateFormat)
f1, err := os.CreateTemp(os.TempDir(), "go-zero-test-"+boundary)
assert.NoError(t, err)
f2, err := os.CreateTemp(os.TempDir(), "go-zero-test-"+boundary)
assert.NoError(t, err)
boundary1 := time.Now().Add(time.Hour * time.Duration(hoursPerDay) * 2).Format(dateFormat)
f3, err := os.CreateTemp(os.TempDir(), "go-zero-test-"+boundary1)
assert.NoError(t, err)
t.Cleanup(func() {
_ = f1.Close()
_ = os.Remove(f1.Name())
_ = f2.Close()
_ = os.Remove(f2.Name())
_ = f3.Close()
_ = os.Remove(f3.Name())
})
rule := SizeLimitRotateRule{
DailyRotateRule: DailyRotateRule{
filename: path.Join(os.TempDir(), "go-zero-test-"),
days: 1,
},
}
assert.NotEmpty(t, rule.OutdatedFiles())
logger := new(RotateLogger)
logger.rule = &rule
logger.maybeDeleteOutdatedFiles()
assert.Empty(t, rule.OutdatedFiles())
})
}
func TestSizeLimitRotateRuleShallRotate(t *testing.T) {
var rule SizeLimitRotateRule
rule.rotatedTime = time.Now().Add(time.Hour * 24).Format(fileTimeFormat)
rule.maxSize = 0
assert.False(t, rule.ShallRotate(0))
rule.maxSize = 100
assert.False(t, rule.ShallRotate(0))
assert.True(t, rule.ShallRotate(101*megaBytes))
}
func TestRotateLoggerClose(t *testing.T) {
t.Run("close", func(t *testing.T) {
filename, err := fs.TempFilenameWithText("foo")
assert.Nil(t, err)
if len(filename) > 0 {
defer os.Remove(filename)
}
logger, err := NewLogger(filename, new(DailyRotateRule), false)
assert.Nil(t, err)
_, err = logger.Write([]byte("foo"))
assert.Nil(t, err)
assert.Nil(t, logger.Close())
})
t.Run("close and write", func(t *testing.T) {
logger := new(RotateLogger)
logger.done = make(chan struct{})
close(logger.done)
_, err := logger.Write([]byte("foo"))
assert.ErrorIs(t, err, ErrLogFileClosed)
})
t.Run("close without losing logs", func(t *testing.T) {
text := "foo"
filename, err := fs.TempFilenameWithText(text)
assert.Nil(t, err)
if len(filename) > 0 {
defer os.Remove(filename)
}
logger, err := NewLogger(filename, new(DailyRotateRule), false)
assert.Nil(t, err)
msg := []byte("foo")
n := 100
for i := 0; i < n; i++ {
_, err = logger.Write(msg)
assert.Nil(t, err)
}
assert.Nil(t, logger.Close())
bs, err := os.ReadFile(filename)
assert.Nil(t, err)
assert.Equal(t, len(msg)*n+len(text), len(bs))
})
}
func TestRotateLoggerGetBackupFilename(t *testing.T) {
filename, err := fs.TempFilenameWithText("foo")
assert.Nil(t, err)
if len(filename) > 0 {
defer os.Remove(filename)
}
logger, err := NewLogger(filename, new(DailyRotateRule), false)
assert.Nil(t, err)
assert.True(t, len(logger.getBackupFilename()) > 0)
logger.backup = ""
assert.True(t, len(logger.getBackupFilename()) > 0)
}
func TestRotateLoggerMayCompressFile(t *testing.T) {
old := os.Stdout
os.Stdout = os.NewFile(0, os.DevNull)
defer func() {
os.Stdout = old
}()
filename, err := fs.TempFilenameWithText("foo")
assert.Nil(t, err)
if len(filename) > 0 {
defer os.Remove(filename)
}
logger, err := NewLogger(filename, new(DailyRotateRule), false)
assert.Nil(t, err)
logger.maybeCompressFile(filename)
_, err = os.Stat(filename)
assert.Nil(t, err)
}
func TestRotateLoggerMayCompressFileTrue(t *testing.T) {
old := os.Stdout
os.Stdout = os.NewFile(0, os.DevNull)
defer func() {
os.Stdout = old
}()
filename, err := fs.TempFilenameWithText("foo")
assert.Nil(t, err)
logger, err := NewLogger(filename, new(DailyRotateRule), true)
assert.Nil(t, err)
if len(filename) > 0 {
defer os.Remove(filepath.Base(logger.getBackupFilename()) + ".gz")
}
logger.maybeCompressFile(filename)
_, err = os.Stat(filename)
assert.NotNil(t, err)
}
func TestRotateLoggerRotate(t *testing.T) {
filename, err := fs.TempFilenameWithText("foo")
assert.Nil(t, err)
logger, err := NewLogger(filename, new(DailyRotateRule), true)
assert.Nil(t, err)
if len(filename) > 0 {
defer func() {
os.Remove(logger.getBackupFilename())
os.Remove(filepath.Base(logger.getBackupFilename()) + ".gz")
}()
}
err = logger.rotate()
switch v := err.(type) {
case *os.LinkError:
// avoid rename error on docker container
assert.Equal(t, syscall.EXDEV, v.Err)
case *os.PathError:
// ignore remove error for tests,
// files are cleaned in GitHub actions.
assert.Equal(t, "remove", v.Op)
default:
assert.Nil(t, err)
}
}
func TestRotateLoggerWrite(t *testing.T) {
filename, err := fs.TempFilenameWithText("foo")
assert.Nil(t, err)
rule := new(DailyRotateRule)
logger, err := NewLogger(filename, rule, true)
assert.Nil(t, err)
if len(filename) > 0 {
defer func() {
os.Remove(logger.getBackupFilename())
os.Remove(filepath.Base(logger.getBackupFilename()) + ".gz")
}()
}
// the following write calls cannot be changed to Write, because of DATA RACE.
logger.write([]byte(`foo`))
rule.rotatedTime = time.Now().Add(-time.Hour * 24).Format(dateFormat)
logger.write([]byte(`bar`))
logger.Close()
logger.write([]byte(`baz`))
}
func TestLogWriterClose(t *testing.T) {
assert.Nil(t, newLogWriter(nil).Close())
}
func TestRotateLoggerWithSizeLimitRotateRuleClose(t *testing.T) {
filename, err := fs.TempFilenameWithText("foo")
assert.Nil(t, err)
if len(filename) > 0 {
defer os.Remove(filename)
}
logger, err := NewLogger(filename, new(SizeLimitRotateRule), false)
assert.Nil(t, err)
_ = logger.Close()
}
func TestRotateLoggerGetBackupWithSizeLimitRotateRuleFilename(t *testing.T) {
filename, err := fs.TempFilenameWithText("foo")
assert.Nil(t, err)
if len(filename) > 0 {
defer os.Remove(filename)
}
logger, err := NewLogger(filename, new(SizeLimitRotateRule), false)
assert.Nil(t, err)
assert.True(t, len(logger.getBackupFilename()) > 0)
logger.backup = ""
assert.True(t, len(logger.getBackupFilename()) > 0)
}
func TestRotateLoggerWithSizeLimitRotateRuleMayCompressFile(t *testing.T) {
old := os.Stdout
os.Stdout = os.NewFile(0, os.DevNull)
defer func() {
os.Stdout = old
}()
filename, err := fs.TempFilenameWithText("foo")
assert.Nil(t, err)
if len(filename) > 0 {
defer os.Remove(filename)
}
logger, err := NewLogger(filename, new(SizeLimitRotateRule), false)
assert.Nil(t, err)
logger.maybeCompressFile(filename)
_, err = os.Stat(filename)
assert.Nil(t, err)
}
func TestRotateLoggerWithSizeLimitRotateRuleMayCompressFileTrue(t *testing.T) {
old := os.Stdout
os.Stdout = os.NewFile(0, os.DevNull)
defer func() {
os.Stdout = old
}()
filename, err := fs.TempFilenameWithText("foo")
assert.Nil(t, err)
logger, err := NewLogger(filename, new(SizeLimitRotateRule), true)
assert.Nil(t, err)
if len(filename) > 0 {
defer os.Remove(filepath.Base(logger.getBackupFilename()) + ".gz")
}
logger.maybeCompressFile(filename)
_, err = os.Stat(filename)
assert.NotNil(t, err)
}
func TestRotateLoggerWithSizeLimitRotateRuleMayCompressFileFailed(t *testing.T) {
old := os.Stdout
os.Stdout = os.NewFile(0, os.DevNull)
defer func() {
os.Stdout = old
}()
filename := random.KeyNew(8, 1)
logger, err := NewLogger(filename, new(SizeLimitRotateRule), true)
defer os.Remove(filename)
if assert.NoError(t, err) {
assert.NotPanics(t, func() {
logger.maybeCompressFile(random.KeyNew(8, 1))
})
}
}
func TestRotateLoggerWithSizeLimitRotateRuleRotate(t *testing.T) {
filename, err := fs.TempFilenameWithText("foo")
assert.Nil(t, err)
logger, err := NewLogger(filename, new(SizeLimitRotateRule), true)
assert.Nil(t, err)
if len(filename) > 0 {
defer func() {
os.Remove(logger.getBackupFilename())
os.Remove(filepath.Base(logger.getBackupFilename()) + ".gz")
}()
}
err = logger.rotate()
switch v := err.(type) {
case *os.LinkError:
// avoid rename error on docker container
assert.Equal(t, syscall.EXDEV, v.Err)
case *os.PathError:
// ignore remove error for tests,
// files are cleaned in GitHub actions.
assert.Equal(t, "remove", v.Op)
default:
assert.Nil(t, err)
}
}
func TestRotateLoggerWithSizeLimitRotateRuleWrite(t *testing.T) {
filename, err := fs.TempFilenameWithText("foo")
assert.Nil(t, err)
rule := new(SizeLimitRotateRule)
logger, err := NewLogger(filename, rule, true)
assert.Nil(t, err)
if len(filename) > 0 {
defer func() {
os.Remove(logger.getBackupFilename())
os.Remove(filepath.Base(logger.getBackupFilename()) + ".gz")
}()
}
// the following write calls cannot be changed to Write, because of DATA RACE.
logger.write([]byte(`foo`))
rule.rotatedTime = time.Now().Add(-time.Hour * 24).Format(dateFormat)
logger.write([]byte(`bar`))
logger.Close()
logger.write([]byte(`baz`))
}
func TestGzipFile(t *testing.T) {
err := errors.New("any error")
t.Run("gzip file open failed", func(t *testing.T) {
fsys := &fakeFileSystem{
openFn: func(name string) (*os.File, error) {
return nil, err
},
}
assert.ErrorIs(t, err, gzipFile("any", fsys))
assert.False(t, fsys.Removed())
})
t.Run("gzip file create failed", func(t *testing.T) {
fsys := &fakeFileSystem{
createFn: func(name string) (*os.File, error) {
return nil, err
},
}
assert.ErrorIs(t, err, gzipFile("any", fsys))
assert.False(t, fsys.Removed())
})
t.Run("gzip file copy failed", func(t *testing.T) {
fsys := &fakeFileSystem{
copyFn: func(writer io.Writer, reader io.Reader) (int64, error) {
return 0, err
},
}
assert.ErrorIs(t, err, gzipFile("any", fsys))
assert.False(t, fsys.Removed())
})
t.Run("gzip file last close failed", func(t *testing.T) {
var called int32
fsys := &fakeFileSystem{
closeFn: func(closer io.Closer) error {
if atomic.AddInt32(&called, 1) > 2 {
return err
}
return nil
},
}
assert.NoError(t, gzipFile("any", fsys))
assert.True(t, fsys.Removed())
})
t.Run("gzip file remove failed", func(t *testing.T) {
fsys := &fakeFileSystem{
removeFn: func(name string) error {
return err
},
}
assert.Error(t, err, gzipFile("any", fsys))
assert.True(t, fsys.Removed())
})
t.Run("gzip file everything ok", func(t *testing.T) {
fsys := &fakeFileSystem{}
assert.NoError(t, gzipFile("any", fsys))
assert.True(t, fsys.Removed())
})
}
func TestRotateLogger_WithExistingFile(t *testing.T) {
const body = "foo"
filename, err := fs.TempFilenameWithText(body)
assert.Nil(t, err)
if len(filename) > 0 {
defer os.Remove(filename)
}
rule := NewSizeLimitRotateRule(filename, "-", 1, 100, 3, false)
logger, err := NewLogger(filename, rule, false)
assert.Nil(t, err)
assert.Equal(t, int64(len(body)), logger.currentSize)
assert.Nil(t, logger.Close())
}
func BenchmarkRotateLogger(b *testing.B) {
filename := "./test.log"
filename2 := "./test2.log"
dailyRotateRuleLogger, err1 := NewLogger(
filename,
DefaultRotateRule(
filename,
backupFileDelimiter,
1,
true,
),
true,
)
if err1 != nil {
b.Logf("Failed to new daily rotate rule logger: %v", err1)
b.FailNow()
}
sizeLimitRotateRuleLogger, err2 := NewLogger(
filename2,
NewSizeLimitRotateRule(
filename,
backupFileDelimiter,
1,
100,
10,
true,
),
true,
)
if err2 != nil {
b.Logf("Failed to new size limit rotate rule logger: %v", err1)
b.FailNow()
}
defer func() {
dailyRotateRuleLogger.Close()
sizeLimitRotateRuleLogger.Close()
os.Remove(filename)
os.Remove(filename2)
}()
b.Run("daily rotate rule", func(b *testing.B) {
for i := 0; i < b.N; i++ {
dailyRotateRuleLogger.write([]byte("testing\ntesting\n"))
}
})
b.Run("size limit rotate rule", func(b *testing.B) {
for i := 0; i < b.N; i++ {
sizeLimitRotateRuleLogger.write([]byte("testing\ntesting\n"))
}
})
}
type fakeFileSystem struct {
removed int32
closeFn func(closer io.Closer) error
copyFn func(writer io.Writer, reader io.Reader) (int64, error)
createFn func(name string) (*os.File, error)
openFn func(name string) (*os.File, error)
removeFn func(name string) error
}
func (f *fakeFileSystem) Close(closer io.Closer) error {
if f.closeFn != nil {
return f.closeFn(closer)
}
return nil
}
func (f *fakeFileSystem) Copy(writer io.Writer, reader io.Reader) (int64, error) {
if f.copyFn != nil {
return f.copyFn(writer, reader)
}
return 0, nil
}
func (f *fakeFileSystem) Create(name string) (*os.File, error) {
if f.createFn != nil {
return f.createFn(name)
}
return nil, nil
}
func (f *fakeFileSystem) Open(name string) (*os.File, error) {
if f.openFn != nil {
return f.openFn(name)
}
return nil, nil
}
func (f *fakeFileSystem) Remove(name string) error {
atomic.AddInt32(&f.removed, 1)
if f.removeFn != nil {
return f.removeFn(name)
}
return nil
}
func (f *fakeFileSystem) Removed() bool {
return atomic.LoadInt32(&f.removed) > 0
}
+15
View File
@@ -0,0 +1,15 @@
package logger
import "log"
type redirector struct{}
// CollectSysLog redirects system log into logx info
func CollectSysLog() {
log.SetOutput(new(redirector))
}
func (r *redirector) Write(p []byte) (n int, err error) {
Info(string(p))
return len(p), nil
}
+61
View File
@@ -0,0 +1,61 @@
package logger
import (
"encoding/json"
"log"
"strings"
"sync/atomic"
"testing"
"github.com/stretchr/testify/assert"
)
const testlog = "Stay hungry, stay foolish."
var testobj = map[string]any{"foo": "bar"}
func TestCollectSysLog(t *testing.T) {
CollectSysLog()
content := getContent(captureOutput(func() {
log.Print(testlog)
}))
assert.True(t, strings.Contains(content, testlog))
}
func TestRedirector(t *testing.T) {
var r redirector
content := getContent(captureOutput(func() {
_, _ = r.Write([]byte(testlog))
}))
assert.Equal(t, testlog, content)
}
func captureOutput(f func()) string {
w := new(mockWriter)
old := writer.Swap(w)
defer writer.Store(old)
prevLevel := atomic.LoadUint32(&logLevel)
SetLevel(InfoLevel)
f()
SetLevel(prevLevel)
return w.String()
}
func getContent(jsonStr string) string {
var entry map[string]any
_ = json.Unmarshal([]byte(jsonStr), &entry)
val, ok := entry[contentKey]
if !ok {
return ""
}
str, ok := val.(string)
if !ok {
return ""
}
return str
}
+61
View File
@@ -0,0 +1,61 @@
package logger
import (
"fmt"
"runtime"
"strings"
"time"
)
func getCaller(callDepth int) string {
var file string
var line int
var ok bool
noMatch := []string{"logger", "@", "model", "default"}
if callDepth > 0 {
_, file, line, ok = runtime.Caller(callDepth)
if !ok {
return ""
}
} else {
// skip logger and External library
for i := 0; i < 20; i++ {
_, file, line, ok = runtime.Caller(i)
if !ok {
return ""
}
if !contains(noMatch, file) {
break
}
}
}
return prettyCaller(file, line)
}
func getTimestamp() string {
return time.Now().Format(timeFormat)
}
func prettyCaller(file string, line int) string {
idx := strings.LastIndexByte(file, '/')
if idx < 0 {
return fmt.Sprintf("%s:%d", file, line)
}
idx = strings.LastIndexByte(file[:idx], '/')
if idx < 0 {
return fmt.Sprintf("%s:%d", file, line)
}
return fmt.Sprintf("%s:%d", file[idx+1:], line)
}
func contains(slice []string, item string) bool {
for _, s := range slice {
if strings.Contains(item, s) {
return true
}
}
return false
}
+72
View File
@@ -0,0 +1,72 @@
package logger
import (
"path/filepath"
"runtime"
"testing"
"time"
"github.com/stretchr/testify/assert"
)
func TestGetCaller(t *testing.T) {
_, file, _, _ := runtime.Caller(0)
assert.Contains(t, getCaller(1), filepath.Base(file))
assert.True(t, len(getCaller(1<<10)) == 0)
}
func TestGetTimestamp(t *testing.T) {
ts := getTimestamp()
tm, err := time.Parse(timeFormat, ts)
assert.Nil(t, err)
assert.True(t, time.Since(tm) < time.Minute)
}
func TestPrettyCaller(t *testing.T) {
tests := []struct {
name string
file string
line int
want string
}{
{
name: "regular",
file: "logx_test.go",
line: 123,
want: "logx_test.go:123",
},
{
name: "relative",
file: "adhoc/logx_test.go",
line: 123,
want: "adhoc/logx_test.go:123",
},
{
name: "long path",
file: "github.com/zeromicro/go-zero/core/logx/util_test.go",
line: 12,
want: "logx/util_test.go:12",
},
{
name: "local path",
file: "/Users/kevin/go-zero/core/logx/util_test.go",
line: 1234,
want: "logx/util_test.go:1234",
},
}
for _, test := range tests {
test := test
t.Run(test.name, func(t *testing.T) {
assert.Equal(t, test.want, prettyCaller(test.file, test.line))
})
}
}
func BenchmarkGetCaller(b *testing.B) {
b.ReportAllocs()
for i := 0; i < b.N; i++ {
getCaller(1)
}
}
+75
View File
@@ -0,0 +1,75 @@
package logger
import (
"errors"
"github.com/perfect-panel/ppanel-server/pkg/syncx"
)
const (
// DebugLevel logs everything
DebugLevel uint32 = iota
// InfoLevel does not include debugs
InfoLevel
// ErrorLevel includes errors, slows, stacks
ErrorLevel
// SevereLevel only log severe messages
SevereLevel
// disableLevel doesn't log any messages
disableLevel = 0xff
)
const (
jsonEncodingType = iota
plainEncodingType
)
const (
plainEncoding = "plain"
plainEncodingSep = '\t'
sizeRotationRule = "size"
accessFilename = "access.log"
errorFilename = "error.log"
severeFilename = "severe.log"
slowFilename = "slow.log"
statFilename = "stat.log"
fileMode = "file"
volumeMode = "volume"
levelAlert = "alert"
levelInfo = "info"
levelError = "error"
levelSevere = "severe"
levelFatal = "fatal"
levelSlow = "slow"
levelStat = "stat"
levelDebug = "debug"
backupFileDelimiter = "-"
nilAngleString = "<nil>"
flags = 0x0
)
const (
callerKey = "caller"
contentKey = "content"
durationKey = "duration"
levelKey = "level"
spanKey = "span"
timestampKey = "timestamp"
traceKey = "trace"
truncatedKey = "truncated"
)
var (
// ErrLogPathNotSet is an error that indicates the log path is not set.
ErrLogPathNotSet = errors.New("log path must be set")
// ErrLogServiceNameNotSet is an error that indicates that the service name is not set.
ErrLogServiceNameNotSet = errors.New("log service name must be set")
// ExitOnFatal defines whether to exit on fatal errors, defined here to make it easier to test.
ExitOnFatal = syncx.ForAtomicBool(true)
truncatedField = Field(truncatedKey, true)
)
+491
View File
@@ -0,0 +1,491 @@
package logger
import (
"bytes"
"encoding/json"
"fmt"
"io"
"log"
"path"
"runtime/debug"
"sync"
"sync/atomic"
fatihcolor "github.com/fatih/color"
"github.com/perfect-panel/ppanel-server/pkg/color"
"github.com/perfect-panel/ppanel-server/pkg/errorx"
)
type (
Writer interface {
Alert(v any)
Close() error
Debug(v any, fields ...LogField)
Error(v any, fields ...LogField)
Info(v any, fields ...LogField)
Severe(v any)
Slow(v any, fields ...LogField)
Stack(v any)
Stat(v any, fields ...LogField)
}
atomicWriter struct {
writer Writer
lock sync.RWMutex
}
comboWriter struct {
writers []Writer
}
concreteWriter struct {
infoLog io.WriteCloser
errorLog io.WriteCloser
severeLog io.WriteCloser
slowLog io.WriteCloser
statLog io.WriteCloser
stackLog io.Writer
}
)
// NewWriter creates a new Writer with the given io.Writer.
func NewWriter(w io.Writer) Writer {
lw := newLogWriter(log.New(w, "", flags))
return &concreteWriter{
infoLog: lw,
errorLog: lw,
severeLog: lw,
slowLog: lw,
statLog: lw,
stackLog: lw,
}
}
func (w *atomicWriter) Load() Writer {
w.lock.RLock()
defer w.lock.RUnlock()
return w.writer
}
func (w *atomicWriter) Store(v Writer) {
w.lock.Lock()
defer w.lock.Unlock()
w.writer = v
}
func (w *atomicWriter) StoreIfNil(v Writer) Writer {
w.lock.Lock()
defer w.lock.Unlock()
if w.writer == nil {
w.writer = v
}
return w.writer
}
func (w *atomicWriter) Swap(v Writer) Writer {
w.lock.Lock()
defer w.lock.Unlock()
old := w.writer
w.writer = v
return old
}
func (c comboWriter) Alert(v any) {
for _, w := range c.writers {
w.Alert(v)
}
}
func (c comboWriter) Close() error {
var be errorx.BatchError
for _, w := range c.writers {
be.Add(w.Close())
}
return be.Err()
}
func (c comboWriter) Debug(v any, fields ...LogField) {
for _, w := range c.writers {
w.Debug(v, fields...)
}
}
func (c comboWriter) Error(v any, fields ...LogField) {
for _, w := range c.writers {
w.Error(v, fields...)
}
}
func (c comboWriter) Info(v any, fields ...LogField) {
for _, w := range c.writers {
w.Info(v, fields...)
}
}
func (c comboWriter) Severe(v any) {
for _, w := range c.writers {
w.Severe(v)
}
}
func (c comboWriter) Slow(v any, fields ...LogField) {
for _, w := range c.writers {
w.Slow(v, fields...)
}
}
func (c comboWriter) Stack(v any) {
for _, w := range c.writers {
w.Stack(v)
}
}
func (c comboWriter) Stat(v any, fields ...LogField) {
for _, w := range c.writers {
w.Stat(v, fields...)
}
}
func newConsoleWriter() Writer {
outLog := newLogWriter(log.New(fatihcolor.Output, "", flags))
errLog := newLogWriter(log.New(fatihcolor.Error, "", flags))
return &concreteWriter{
infoLog: outLog,
errorLog: errLog,
severeLog: errLog,
slowLog: errLog,
stackLog: newLessWriter(errLog, options.logStackCooldownMills),
statLog: outLog,
}
}
func newFileWriter(c LogConf) (Writer, error) {
var err error
var opts []LogOption
var infoLog io.WriteCloser
var errorLog io.WriteCloser
var severeLog io.WriteCloser
var slowLog io.WriteCloser
var statLog io.WriteCloser
var stackLog io.Writer
if len(c.Path) == 0 {
return nil, ErrLogPathNotSet
}
opts = append(opts, WithCooldownMillis(c.StackCooldownMillis))
if c.Compress {
opts = append(opts, WithGzip())
}
if c.KeepDays > 0 {
opts = append(opts, WithKeepDays(c.KeepDays))
}
if c.MaxBackups > 0 {
opts = append(opts, WithMaxBackups(c.MaxBackups))
}
if c.MaxSize > 0 {
opts = append(opts, WithMaxSize(c.MaxSize))
}
opts = append(opts, WithRotation(c.Rotation))
accessFile := path.Join(c.Path, accessFilename)
errorFile := path.Join(c.Path, errorFilename)
severeFile := path.Join(c.Path, severeFilename)
slowFile := path.Join(c.Path, slowFilename)
statFile := path.Join(c.Path, statFilename)
handleOptions(opts)
setupLogLevel(c)
if infoLog, err = createOutput(accessFile); err != nil {
return nil, err
}
if errorLog, err = createOutput(errorFile); err != nil {
return nil, err
}
if severeLog, err = createOutput(severeFile); err != nil {
return nil, err
}
if slowLog, err = createOutput(slowFile); err != nil {
return nil, err
}
if statLog, err = createOutput(statFile); err != nil {
return nil, err
}
stackLog = newLessWriter(errorLog, options.logStackCooldownMills)
return &concreteWriter{
infoLog: infoLog,
errorLog: errorLog,
severeLog: severeLog,
slowLog: slowLog,
statLog: statLog,
stackLog: stackLog,
}, nil
}
func (w *concreteWriter) Alert(v any) {
output(w.errorLog, levelAlert, v)
}
func (w *concreteWriter) Close() error {
if err := w.infoLog.Close(); err != nil {
return err
}
if err := w.errorLog.Close(); err != nil {
return err
}
if err := w.severeLog.Close(); err != nil {
return err
}
if err := w.slowLog.Close(); err != nil {
return err
}
return w.statLog.Close()
}
func (w *concreteWriter) Debug(v any, fields ...LogField) {
output(w.infoLog, levelDebug, v, fields...)
}
func (w *concreteWriter) Error(v any, fields ...LogField) {
output(w.errorLog, levelError, v, fields...)
}
func (w *concreteWriter) Info(v any, fields ...LogField) {
output(w.infoLog, levelInfo, v, fields...)
}
func (w *concreteWriter) Severe(v any) {
output(w.severeLog, levelFatal, v)
}
func (w *concreteWriter) Slow(v any, fields ...LogField) {
output(w.slowLog, levelSlow, v, fields...)
}
func (w *concreteWriter) Stack(v any) {
output(w.stackLog, levelError, v)
}
func (w *concreteWriter) Stat(v any, fields ...LogField) {
output(w.statLog, levelStat, v, fields...)
}
type nopWriter struct{}
func (n nopWriter) Alert(_ any) {
}
func (n nopWriter) Close() error {
return nil
}
func (n nopWriter) Debug(_ any, _ ...LogField) {
}
func (n nopWriter) Error(_ any, _ ...LogField) {
}
func (n nopWriter) Info(_ any, _ ...LogField) {
}
func (n nopWriter) Severe(_ any) {
}
func (n nopWriter) Slow(_ any, _ ...LogField) {
}
func (n nopWriter) Stack(_ any) {
}
func (n nopWriter) Stat(_ any, _ ...LogField) {
}
func buildPlainFields(fields logEntry) []string {
orderedKeys := []string{"duration", "caller"}
items := make([]string, 0, len(fields))
for _, key := range orderedKeys {
// append the keys that have been set
if value, exists := fields[key]; exists {
items = append(items, fmt.Sprintf("%s=%+v", key, value))
}
}
for key, value := range fields {
if !contains(orderedKeys, key) { // skip the keys that have been appended
items = append(items, fmt.Sprintf("%s=%+v", key, value))
}
}
return items
}
func combineGlobalFields(fields []LogField) []LogField {
globals := globalFields.Load()
if globals == nil {
return fields
}
gf := globals.([]LogField)
ret := make([]LogField, 0, len(gf)+len(fields))
ret = append(ret, gf...)
ret = append(ret, fields...)
return ret
}
func marshalJson(t interface{}) ([]byte, error) {
var buf bytes.Buffer
encoder := json.NewEncoder(&buf)
encoder.SetEscapeHTML(false)
err := encoder.Encode(t)
// go 1.5+ will append a newline to the end of the json string
// https://github.com/golang/go/issues/13520
if l := buf.Len(); l > 0 && buf.Bytes()[l-1] == '\n' {
buf.Truncate(l - 1)
}
return buf.Bytes(), err
}
func output(writer io.Writer, level string, val any, fields ...LogField) {
// only truncate string content, don't know how to truncate the values of other types.
if v, ok := val.(string); ok {
maxLen := atomic.LoadUint32(&maxContentLength)
if maxLen > 0 && len(v) > int(maxLen) {
val = v[:maxLen]
fields = append(fields, truncatedField)
}
}
fields = combineGlobalFields(fields)
// +3 for timestamp, level and content
entry := make(logEntry, len(fields)+3)
for _, field := range fields {
entry[field.Key] = field.Value
}
switch atomic.LoadUint32(&encoding) {
case plainEncodingType:
plainFields := buildPlainFields(entry)
writePlainAny(writer, level, val, plainFields...)
default:
entry[timestampKey] = getTimestamp()
entry[levelKey] = level
entry[contentKey] = val
writeJson(writer, entry)
}
}
func wrapLevelWithColor(level string) string {
var colour color.Color
switch level {
case levelAlert:
colour = color.FgRed
case levelError:
colour = color.FgRed
case levelFatal:
colour = color.FgRed
case levelInfo:
colour = color.FgBlue
case levelSlow:
colour = color.FgYellow
case levelDebug:
colour = color.FgYellow
case levelStat:
colour = color.FgGreen
}
if colour == color.NoColor {
return level
}
return color.WithColorPadding(level, colour)
}
func writeJson(writer io.Writer, info any) {
if content, err := marshalJson(info); err != nil {
log.Printf("err: %s\n\n%s", err.Error(), debug.Stack())
} else if writer == nil {
log.Println(string(content))
} else {
if _, err := writer.Write(append(content, '\n')); err != nil {
log.Println(err.Error())
}
}
}
func writePlainAny(writer io.Writer, level string, val any, fields ...string) {
level = wrapLevelWithColor(level)
switch v := val.(type) {
case string:
writePlainText(writer, level, v, fields...)
case error:
writePlainText(writer, level, v.Error(), fields...)
case fmt.Stringer:
writePlainText(writer, level, v.String(), fields...)
default:
writePlainValue(writer, level, v, fields...)
}
}
func writePlainText(writer io.Writer, level, msg string, fields ...string) {
var buf bytes.Buffer
buf.WriteString(getTimestamp())
buf.WriteByte(plainEncodingSep)
buf.WriteString(level)
buf.WriteByte(plainEncodingSep)
buf.WriteString(msg)
for _, item := range fields {
buf.WriteByte(plainEncodingSep)
buf.WriteString(item)
}
buf.WriteByte('\n')
if writer == nil {
log.Println(buf.String())
return
}
if _, err := writer.Write(buf.Bytes()); err != nil {
log.Println(err.Error())
}
}
func writePlainValue(writer io.Writer, level string, val any, fields ...string) {
var buf bytes.Buffer
buf.WriteString(getTimestamp())
buf.WriteByte(plainEncodingSep)
buf.WriteString(level)
buf.WriteByte(plainEncodingSep)
if err := json.NewEncoder(&buf).Encode(val); err != nil {
log.Printf("err: %s\n\n%s", err.Error(), debug.Stack())
return
}
for _, item := range fields {
buf.WriteByte(plainEncodingSep)
buf.WriteString(item)
}
buf.WriteByte('\n')
if writer == nil {
log.Println(buf.String())
return
}
if _, err := writer.Write(buf.Bytes()); err != nil {
log.Println(err.Error())
}
}
+440
View File
@@ -0,0 +1,440 @@
package logger
import (
"bytes"
"encoding/json"
"errors"
"log"
"sync/atomic"
"testing"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/mock"
)
func TestNewWriter(t *testing.T) {
const literal = "foo bar"
var buf bytes.Buffer
w := NewWriter(&buf)
w.Info(literal)
assert.Contains(t, buf.String(), literal)
buf.Reset()
w.Debug(literal)
assert.Contains(t, buf.String(), literal)
}
func TestConsoleWriter(t *testing.T) {
var buf bytes.Buffer
w := newConsoleWriter()
lw := newLogWriter(log.New(&buf, "", 0))
w.(*concreteWriter).errorLog = lw
w.Alert("foo bar 1")
var val mockedEntry
if err := json.Unmarshal(buf.Bytes(), &val); err != nil {
t.Fatal(err)
}
assert.Equal(t, levelAlert, val.Level)
assert.Equal(t, "foo bar 1", val.Content)
buf.Reset()
w.(*concreteWriter).errorLog = lw
w.Error("foo bar 2")
if err := json.Unmarshal(buf.Bytes(), &val); err != nil {
t.Fatal(err)
}
assert.Equal(t, levelError, val.Level)
assert.Equal(t, "foo bar 2", val.Content)
buf.Reset()
w.(*concreteWriter).infoLog = lw
w.Info("foo bar 3")
if err := json.Unmarshal(buf.Bytes(), &val); err != nil {
t.Fatal(err)
}
assert.Equal(t, levelInfo, val.Level)
assert.Equal(t, "foo bar 3", val.Content)
buf.Reset()
w.(*concreteWriter).severeLog = lw
w.Severe("foo bar 4")
if err := json.Unmarshal(buf.Bytes(), &val); err != nil {
t.Fatal(err)
}
assert.Equal(t, levelFatal, val.Level)
assert.Equal(t, "foo bar 4", val.Content)
buf.Reset()
w.(*concreteWriter).slowLog = lw
w.Slow("foo bar 5")
if err := json.Unmarshal(buf.Bytes(), &val); err != nil {
t.Fatal(err)
}
assert.Equal(t, levelSlow, val.Level)
assert.Equal(t, "foo bar 5", val.Content)
buf.Reset()
w.(*concreteWriter).statLog = lw
w.Stat("foo bar 6")
if err := json.Unmarshal(buf.Bytes(), &val); err != nil {
t.Fatal(err)
}
assert.Equal(t, levelStat, val.Level)
assert.Equal(t, "foo bar 6", val.Content)
w.(*concreteWriter).infoLog = hardToCloseWriter{}
assert.NotNil(t, w.Close())
w.(*concreteWriter).infoLog = easyToCloseWriter{}
w.(*concreteWriter).errorLog = hardToCloseWriter{}
assert.NotNil(t, w.Close())
w.(*concreteWriter).errorLog = easyToCloseWriter{}
w.(*concreteWriter).severeLog = hardToCloseWriter{}
assert.NotNil(t, w.Close())
w.(*concreteWriter).severeLog = easyToCloseWriter{}
w.(*concreteWriter).slowLog = hardToCloseWriter{}
assert.NotNil(t, w.Close())
w.(*concreteWriter).slowLog = easyToCloseWriter{}
w.(*concreteWriter).statLog = hardToCloseWriter{}
assert.NotNil(t, w.Close())
w.(*concreteWriter).statLog = easyToCloseWriter{}
}
func TestNewFileWriter(t *testing.T) {
t.Run("access", func(t *testing.T) {
_, err := newFileWriter(LogConf{
Path: "/not-exists",
})
assert.Error(t, err)
})
}
func TestNopWriter(t *testing.T) {
assert.NotPanics(t, func() {
var w nopWriter
w.Alert("foo")
w.Debug("foo")
w.Error("foo")
w.Info("foo")
w.Severe("foo")
w.Stack("foo")
w.Stat("foo")
w.Slow("foo")
_ = w.Close()
})
}
func TestWriteJson(t *testing.T) {
var buf bytes.Buffer
log.SetOutput(&buf)
writeJson(nil, "foo")
assert.Contains(t, buf.String(), "foo")
buf.Reset()
writeJson(hardToWriteWriter{}, "foo")
assert.Contains(t, buf.String(), "write error")
buf.Reset()
writeJson(nil, make(chan int))
assert.Contains(t, buf.String(), "unsupported type")
buf.Reset()
type C struct {
RC func()
}
writeJson(nil, C{
RC: func() {},
})
assert.Contains(t, buf.String(), "runtime/debug.Stack")
}
func TestWritePlainAny(t *testing.T) {
var buf bytes.Buffer
log.SetOutput(&buf)
writePlainAny(nil, levelInfo, "foo")
assert.Contains(t, buf.String(), "foo")
buf.Reset()
writePlainAny(nil, levelDebug, make(chan int))
assert.Contains(t, buf.String(), "unsupported type")
writePlainAny(nil, levelDebug, 100)
assert.Contains(t, buf.String(), "100")
buf.Reset()
writePlainAny(nil, levelError, make(chan int))
assert.Contains(t, buf.String(), "unsupported type")
writePlainAny(nil, levelSlow, 100)
assert.Contains(t, buf.String(), "100")
buf.Reset()
writePlainAny(hardToWriteWriter{}, levelStat, 100)
assert.Contains(t, buf.String(), "write error")
buf.Reset()
writePlainAny(hardToWriteWriter{}, levelSevere, "foo")
assert.Contains(t, buf.String(), "write error")
buf.Reset()
writePlainAny(hardToWriteWriter{}, levelAlert, "foo")
assert.Contains(t, buf.String(), "write error")
buf.Reset()
writePlainAny(hardToWriteWriter{}, levelFatal, "foo")
assert.Contains(t, buf.String(), "write error")
buf.Reset()
type C struct {
RC func()
}
writePlainAny(nil, levelError, C{
RC: func() {},
})
assert.Contains(t, buf.String(), "runtime/debug.Stack")
}
func TestWritePlainDuplicate(t *testing.T) {
old := atomic.SwapUint32(&encoding, plainEncodingType)
t.Cleanup(func() {
atomic.StoreUint32(&encoding, old)
})
var buf bytes.Buffer
output(&buf, levelInfo, "foo", LogField{
Key: "first",
Value: "a",
}, LogField{
Key: "first",
Value: "b",
})
assert.Contains(t, buf.String(), "foo")
assert.NotContains(t, buf.String(), "first=a")
assert.Contains(t, buf.String(), "first=b")
buf.Reset()
output(&buf, levelInfo, "foo", LogField{
Key: "first",
Value: "a",
}, LogField{
Key: "first",
Value: "b",
}, LogField{
Key: "second",
Value: "c",
})
assert.Contains(t, buf.String(), "foo")
assert.NotContains(t, buf.String(), "first=a")
assert.Contains(t, buf.String(), "first=b")
assert.Contains(t, buf.String(), "second=c")
}
func TestLogWithLimitContentLength(t *testing.T) {
maxLen := atomic.LoadUint32(&maxContentLength)
atomic.StoreUint32(&maxContentLength, 10)
t.Cleanup(func() {
atomic.StoreUint32(&maxContentLength, maxLen)
})
t.Run("alert", func(t *testing.T) {
var buf bytes.Buffer
w := NewWriter(&buf)
w.Info("1234567890")
var v1 mockedEntry
if err := json.Unmarshal(buf.Bytes(), &v1); err != nil {
t.Fatal(err)
}
assert.Equal(t, "1234567890", v1.Content)
assert.False(t, v1.Truncated)
buf.Reset()
var v2 mockedEntry
w.Info("12345678901")
if err := json.Unmarshal(buf.Bytes(), &v2); err != nil {
t.Fatal(err)
}
assert.Equal(t, "1234567890", v2.Content)
assert.True(t, v2.Truncated)
})
}
func TestComboWriter(t *testing.T) {
var mockWriters []Writer
for i := 0; i < 3; i++ {
mockWriters = append(mockWriters, new(tracedWriter))
}
cw := comboWriter{
writers: mockWriters,
}
t.Run("Alert", func(t *testing.T) {
for _, mw := range cw.writers {
mw.(*tracedWriter).On("Alert", "test alert").Once()
}
cw.Alert("test alert")
for _, mw := range cw.writers {
mw.(*tracedWriter).AssertCalled(t, "Alert", "test alert")
}
})
t.Run("Close", func(t *testing.T) {
for i := range cw.writers {
if i == 1 {
cw.writers[i].(*tracedWriter).On("Close").Return(errors.New("error")).Once()
} else {
cw.writers[i].(*tracedWriter).On("Close").Return(nil).Once()
}
}
err := cw.Close()
assert.Error(t, err)
for _, mw := range cw.writers {
mw.(*tracedWriter).AssertCalled(t, "Close")
}
})
t.Run("Debug", func(t *testing.T) {
fields := []LogField{{Key: "key", Value: "value"}}
for _, mw := range cw.writers {
mw.(*tracedWriter).On("Debug", "test debug", fields).Once()
}
cw.Debug("test debug", fields...)
for _, mw := range cw.writers {
mw.(*tracedWriter).AssertCalled(t, "Debug", "test debug", fields)
}
})
t.Run("Error", func(t *testing.T) {
fields := []LogField{{Key: "key", Value: "value"}}
for _, mw := range cw.writers {
mw.(*tracedWriter).On("Error", "test error", fields).Once()
}
cw.Error("test error", fields...)
for _, mw := range cw.writers {
mw.(*tracedWriter).AssertCalled(t, "Error", "test error", fields)
}
})
t.Run("Info", func(t *testing.T) {
fields := []LogField{{Key: "key", Value: "value"}}
for _, mw := range cw.writers {
mw.(*tracedWriter).On("Info", "test info", fields).Once()
}
cw.Info("test info", fields...)
for _, mw := range cw.writers {
mw.(*tracedWriter).AssertCalled(t, "Info", "test info", fields)
}
})
t.Run("Severe", func(t *testing.T) {
for _, mw := range cw.writers {
mw.(*tracedWriter).On("Severe", "test severe").Once()
}
cw.Severe("test severe")
for _, mw := range cw.writers {
mw.(*tracedWriter).AssertCalled(t, "Severe", "test severe")
}
})
t.Run("Slow", func(t *testing.T) {
fields := []LogField{{Key: "key", Value: "value"}}
for _, mw := range cw.writers {
mw.(*tracedWriter).On("Slow", "test slow", fields).Once()
}
cw.Slow("test slow", fields...)
for _, mw := range cw.writers {
mw.(*tracedWriter).AssertCalled(t, "Slow", "test slow", fields)
}
})
t.Run("Stack", func(t *testing.T) {
for _, mw := range cw.writers {
mw.(*tracedWriter).On("Stack", "test stack").Once()
}
cw.Stack("test stack")
for _, mw := range cw.writers {
mw.(*tracedWriter).AssertCalled(t, "Stack", "test stack")
}
})
t.Run("Stat", func(t *testing.T) {
fields := []LogField{{Key: "key", Value: "value"}}
for _, mw := range cw.writers {
mw.(*tracedWriter).On("Stat", "test stat", fields).Once()
}
cw.Stat("test stat", fields...)
for _, mw := range cw.writers {
mw.(*tracedWriter).AssertCalled(t, "Stat", "test stat", fields)
}
})
}
type mockedEntry struct {
Level string `json:"level"`
Content string `json:"content"`
Truncated bool `json:"truncated"`
}
type easyToCloseWriter struct{}
func (h easyToCloseWriter) Write(_ []byte) (_ int, _ error) {
return
}
func (h easyToCloseWriter) Close() error {
return nil
}
type hardToCloseWriter struct{}
func (h hardToCloseWriter) Write(_ []byte) (_ int, _ error) {
return
}
func (h hardToCloseWriter) Close() error {
return errors.New("close error")
}
type hardToWriteWriter struct{}
func (h hardToWriteWriter) Write(_ []byte) (_ int, _ error) {
return 0, errors.New("write error")
}
type tracedWriter struct {
mock.Mock
}
func (w *tracedWriter) Alert(v any) {
w.Called(v)
}
func (w *tracedWriter) Close() error {
args := w.Called()
return args.Error(0)
}
func (w *tracedWriter) Debug(v any, fields ...LogField) {
w.Called(v, fields)
}
func (w *tracedWriter) Error(v any, fields ...LogField) {
w.Called(v, fields)
}
func (w *tracedWriter) Info(v any, fields ...LogField) {
w.Called(v, fields)
}
func (w *tracedWriter) Severe(v any) {
w.Called(v)
}
func (w *tracedWriter) Slow(v any, fields ...LogField) {
w.Called(v, fields)
}
func (w *tracedWriter) Stack(v any) {
w.Called(v)
}
func (w *tracedWriter) Stat(v any, fields ...LogField) {
w.Called(v, fields)
}