Skip to content

Commit

Permalink
feat: non-sugared logging
Browse files Browse the repository at this point in the history
  • Loading branch information
fracasula committed Nov 17, 2023
1 parent 511b8a8 commit bfeca98
Show file tree
Hide file tree
Showing 9 changed files with 664 additions and 131 deletions.
2 changes: 1 addition & 1 deletion go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -122,7 +122,7 @@ require (
go.opentelemetry.io/otel/exporters/otlp/otlptrace v1.19.0 // indirect
go.opentelemetry.io/otel/trace v1.19.0 // indirect
go.opentelemetry.io/proto/otlp v1.0.0 // indirect
go.uber.org/multierr v1.10.0 // indirect
go.uber.org/multierr v1.11.0 // indirect
golang.org/x/crypto v0.15.0 // indirect
golang.org/x/mod v0.12.0 // indirect
golang.org/x/net v0.18.0 // indirect
Expand Down
4 changes: 2 additions & 2 deletions go.sum
Original file line number Diff line number Diff line change
Expand Up @@ -455,8 +455,8 @@ go.opentelemetry.io/proto/otlp v1.0.0 h1:T0TX0tmXU8a3CbNXzEKGeU5mIVOdf0oykP+u2lI
go.opentelemetry.io/proto/otlp v1.0.0/go.mod h1:Sy6pihPLfYHkr3NkUbEhGHFhINUSI/v80hjKIs5JXpM=
go.uber.org/goleak v1.2.1 h1:NBol2c7O1ZokfZ0LEU9K6Whx/KnwvepVetCUhtKja4A=
go.uber.org/goleak v1.2.1/go.mod h1:qlT2yGI9QafXHhZZLxlSuNsMw3FFLxBr+tBRlmO1xH4=
go.uber.org/multierr v1.10.0 h1:S0h4aNzvfcFsC3dRF1jLoaov7oRaKqRGC/pUEJ2yvPQ=
go.uber.org/multierr v1.10.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y=
go.uber.org/multierr v1.11.0 h1:blXXJkSxSSfBVBlC76pxqeO+LN3aDfLQo+309xJstO0=
go.uber.org/multierr v1.11.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y=
go.uber.org/zap v1.26.0 h1:sI7k6L95XOKS281NhVKOFCUNIvv9e0w4BF8N3u+tCRo=
go.uber.org/zap v1.26.0/go.mod h1:dtElttAiwGvoJ/vj4IwHBS/gXsEu/pZ50mUIRWuG0so=
golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w=
Expand Down
98 changes: 98 additions & 0 deletions logger/benchmark_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,98 @@
package logger

import (
"testing"

"go.uber.org/zap"
"go.uber.org/zap/zapcore"

"github.com/rudderlabs/rudder-go-kit/config"
)

// BenchmarkKit results:
// non-sugared: 496.6 ns/op
// sugared: 723.5 ns/op
func BenchmarkKit(b *testing.B) {
c := config.New()
c.Set("LOG_LEVEL", "DEBUG")
c.Set("Logger.consoleJsonFormat", "json")
c.Set("Logger.discardConsole", true)
c.Set("Logger.enableFileNameInLog", true)

b.Run("non-sugared", func(b *testing.B) {
f := NewFactory(c)
l := f.NewLogger()
defer f.Sync()

fields := []Field{
NewStringField("key1", "111"), NewStringField("key2", "222"),
NewStringField("key3", "333"), NewStringField("key4", "444"),
NewStringField("key5", "555"), NewStringField("key6", "666"),
NewStringField("key7", "777"), NewStringField("key8", "888"),
NewStringField("key9", "999"), NewStringField("key10", "101010"),
}

b.ResetTimer()
b.RunParallel(func(pb *testing.PB) {
for pb.Next() {
l.Debugn("test", fields...)
}
})
})

b.Run("sugared", func(b *testing.B) {
f := NewFactory(c)
l := f.NewLogger()
defer f.Sync()

fields := []any{
"key1", "111", "key2", "222",
"key3", "333", "key4", "444",
"key5", "555", "key6", "666",
"key7", "777", "key8", "888",
"key9", "999", "key10", "101010",
}

b.ResetTimer()
b.RunParallel(func(pb *testing.PB) {
for pb.Next() {
l.Debugw("test", fields...)
}
})
})
}

// BenchmarkZap results:
// Zap: 60.96 ns/op
// Zap.Sugar: 94.57 ns/op
func BenchmarkZap(b *testing.B) {
newZap := func(lvl zapcore.Level) *zap.Logger {
ec := zap.NewProductionEncoderConfig()
ec.EncodeDuration = zapcore.NanosDurationEncoder
ec.EncodeTime = zapcore.EpochNanosTimeEncoder
enc := zapcore.NewJSONEncoder(ec)
return zap.New(zapcore.NewCore(
enc,
&discarder{},
lvl,
))
}
b.Run("Zap", func(b *testing.B) {
logger := newZap(zapcore.DebugLevel)
b.ResetTimer()
b.RunParallel(func(pb *testing.PB) {
for pb.Next() {
logger.Debug("message", zap.String("key1", "111"), zap.String("key2", "222"))
}
})
})
b.Run("Zap.Sugar", func(b *testing.B) {
logger := newZap(zapcore.DebugLevel).Sugar()
b.ResetTimer()
b.RunParallel(func(pb *testing.PB) {
for pb.Next() {
logger.Debugw("message", "key1", "111", "key2", "222")
}
})
})
}
33 changes: 23 additions & 10 deletions logger/factory.go
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
package logger

import (
"io"
"os"
"strings"

Expand All @@ -11,7 +12,7 @@ import (
"github.com/rudderlabs/rudder-go-kit/config"
)

// default factory instance
// Default factory instance
var Default *Factory

func init() {
Expand All @@ -32,13 +33,15 @@ func NewFactory(config *config.Config, options ...Option) *Factory {
option.apply(f)
}
f.zap = newZapLogger(config, f.config)
f.sugaredZap = f.zap.Sugar()
return f
}

// Factory is a factory for creating new loggers
type Factory struct {
config *factoryConfig
zap *zap.SugaredLogger
config *factoryConfig
zap *zap.Logger
sugaredZap *zap.SugaredLogger
}

// NewLogger creates a new logger using the default logger factory
Expand All @@ -49,8 +52,9 @@ func NewLogger() Logger {
// NewLogger creates a new logger
func (f *Factory) NewLogger() Logger {
return &logger{
logConfig: f.config,
zap: f.zap,
logConfig: f.config,
zap: f.zap,
sugaredZap: f.sugaredZap,
}
}

Expand All @@ -73,7 +77,7 @@ func SetLogLevel(name, levelStr string) error {
func (f *Factory) SetLogLevel(name, levelStr string) error {
err := f.config.SetLogLevel(name, levelStr)
if err != nil {
f.zap.Info(f.config.levelConfig)
f.sugaredZap.Info(f.config.levelConfig)

Check warning on line 80 in logger/factory.go

View check run for this annotation

Codecov / codecov/patch

logger/factory.go#L80

Added line #L80 was not covered by tests
}
return err
}
Expand All @@ -86,6 +90,7 @@ func Sync() {
// Sync flushes the loggers' output buffers
func (f *Factory) Sync() {
_ = f.zap.Sync()
_ = f.sugaredZap.Sync()
}

func newConfig(config *config.Config) *factoryConfig {
Expand Down Expand Up @@ -124,10 +129,14 @@ func newConfig(config *config.Config) *factoryConfig {
}

// newZapLogger configures the zap logger based on the config provide in config.toml
func newZapLogger(config *config.Config, fc *factoryConfig) *zap.SugaredLogger {
func newZapLogger(config *config.Config, fc *factoryConfig) *zap.Logger {
var cores []zapcore.Core
if config.GetBool("Logger.enableConsole", true) {
writer := zapcore.Lock(os.Stdout)
var writeSyncer zapcore.WriteSyncer = os.Stdout
if config.GetBool("Logger.discardConsole", false) {
writeSyncer = &discarder{}
}

Check warning on line 138 in logger/factory.go

View check run for this annotation

Codecov / codecov/patch

logger/factory.go#L137-L138

Added lines #L137 - L138 were not covered by tests
writer := zapcore.Lock(writeSyncer)
core := zapcore.NewCore(zapEncoder(config, config.GetBool("Logger.consoleJsonFormat", false)), writer, zapcore.DebugLevel)
cores = append(cores, core)
}
Expand Down Expand Up @@ -155,8 +164,7 @@ func newZapLogger(config *config.Config, fc *factoryConfig) *zap.SugaredLogger {
options = append(options, zap.WithClock(fc.clock))
}

zapLogger := zap.New(combinedCore, options...)
return zapLogger.Sugar()
return zap.New(combinedCore, options...)
}

// zapEncoder configures the output of the log
Expand All @@ -174,3 +182,8 @@ func zapEncoder(config *config.Config, json bool) zapcore.Encoder {
}
return zapcore.NewConsoleEncoder(encoderConfig)
}

type discarder struct{}

func (d *discarder) Sync() error { return nil }
func (d *discarder) Write(b []byte) (int, error) { return io.Discard.Write(b) }

Check warning on line 189 in logger/factory.go

View check run for this annotation

Codecov / codecov/patch

logger/factory.go#L188-L189

Added lines #L188 - L189 were not covered by tests
125 changes: 125 additions & 0 deletions logger/field.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,125 @@
package logger

import (
"time"

"go.uber.org/zap"
)

type FieldType uint8

const (
UnknownType FieldType = iota
StringType
IntType
BoolType
FloatType
TimeType
DurationType
ErrorType
)

type Field struct {
name string
fieldType FieldType

unknown any
string string
int int64
bool bool
float float64
time time.Time
duration time.Duration
error error
}

func (f Field) Name() string { return f.name }
func (f Field) Value() any {
switch f.fieldType {
case StringType:
return f.string
case IntType:
return f.int
case BoolType:
return f.bool
case FloatType:
return f.float
case TimeType:
return f.time
case DurationType:
return f.duration
case ErrorType:
return f.error
default:
return f.unknown

Check warning on line 54 in logger/field.go

View check run for this annotation

Codecov / codecov/patch

logger/field.go#L36-L54

Added lines #L36 - L54 were not covered by tests
}
}

func (f Field) toZap() zap.Field {
switch f.fieldType {
case StringType:
return zap.String(f.name, f.string)
case IntType:
return zap.Int64(f.name, f.int)
case BoolType:
return zap.Bool(f.name, f.bool)
case FloatType:
return zap.Float64(f.name, f.float)
case TimeType:
return zap.Time(f.name, f.time)
case DurationType:
return zap.Duration(f.name, f.duration)
case ErrorType:
return zap.Error(f.error)
default:
return zap.Any(f.name, f.unknown)
}
}

func NewField(key string, v any) Field { return Field{name: key, unknown: v} }

func NewStringField(key, v string) Field {
return Field{name: key, string: v, fieldType: StringType}
}

func NewIntField(key string, v int64) Field {
return Field{name: key, int: v, fieldType: IntType}
}

func NewBoolField(key string, v bool) Field {
return Field{name: key, bool: v, fieldType: BoolType}
}

func NewFloatField(key string, v float64) Field {
return Field{name: key, float: v, fieldType: FloatType}
}

func NewTimeField(key string, v time.Time) Field {
return Field{name: key, time: v, fieldType: TimeType}
}

func NewDurationField(key string, v time.Duration) Field {
return Field{name: key, duration: v, fieldType: DurationType}
}

func NewErrorField(v error) Field {
return Field{error: v, fieldType: ErrorType}
}

// Expand is useful if you want to use the type Field with the sugared logger
// e.g. l.Infow("my message", logger.Expand(f1, f2, f3)...)
func Expand(fields ...Field) []any {
result := make([]any, 0, len(fields)*2)
for _, field := range fields {
result = append(result, field.name, field.Value())
}
return result

Check warning on line 116 in logger/field.go

View check run for this annotation

Codecov / codecov/patch

logger/field.go#L111-L116

Added lines #L111 - L116 were not covered by tests
}

func toZap(fields []Field) []zap.Field {
result := make([]zap.Field, 0, len(fields))
for _, field := range fields {
result = append(result, field.toZap())
}
return result
}
Loading

0 comments on commit bfeca98

Please sign in to comment.