From 5e364650780e9f09921c29117b7c62d90ce4eba3 Mon Sep 17 00:00:00 2001 From: Karan Sharma Date: Thu, 7 Jul 2022 14:06:35 +0530 Subject: [PATCH 1/2] feat: add default options for logger - Removes the .Set() method for logger. - Specify opts in .New() for initialising logger. --- benchmark_test.go | 28 ++++++-------- examples/main.go | 24 +++++------- log.go | 94 +++++++++++++++++------------------------------ log_test.go | 22 +++++------ 4 files changed, 62 insertions(+), 106 deletions(-) diff --git a/benchmark_test.go b/benchmark_test.go index 8e84f8b..4a61394 100644 --- a/benchmark_test.go +++ b/benchmark_test.go @@ -9,7 +9,7 @@ import ( ) func BenchmarkNoField(b *testing.B) { - logger := logf.New(io.Discard) + logger := logf.New(logf.Opts{Writer: io.Discard}) b.ReportAllocs() b.ResetTimer() b.RunParallel(func(p *testing.PB) { @@ -20,7 +20,7 @@ func BenchmarkNoField(b *testing.B) { } func BenchmarkOneField(b *testing.B) { - logger := logf.New(io.Discard) + logger := logf.New(logf.Opts{Writer: io.Discard}) b.ReportAllocs() b.ResetTimer() b.RunParallel(func(p *testing.PB) { @@ -31,7 +31,7 @@ func BenchmarkOneField(b *testing.B) { } func BenchmarkThreeFields(b *testing.B) { - logger := logf.New(io.Discard) + logger := logf.New(logf.Opts{Writer: io.Discard}) b.ReportAllocs() b.ResetTimer() @@ -45,7 +45,7 @@ func BenchmarkThreeFields(b *testing.B) { } func BenchmarkErrorField(b *testing.B) { - logger := logf.New(io.Discard) + logger := logf.New(logf.Opts{Writer: io.Discard}) b.ReportAllocs() b.ResetTimer() @@ -59,7 +59,7 @@ func BenchmarkErrorField(b *testing.B) { } func BenchmarkHugePayload(b *testing.B) { - logger := logf.New(io.Discard) + logger := logf.New(logf.Opts{Writer: io.Discard}) b.ReportAllocs() b.ResetTimer() @@ -82,8 +82,7 @@ func BenchmarkHugePayload(b *testing.B) { } func BenchmarkThreeFields_WithCaller(b *testing.B) { - logger := logf.New(io.Discard) - logger.SetCallerFrame(true, 3) + logger := logf.New(logf.Opts{Writer: io.Discard, CallerSkipFrameCount: 3, EnableCaller: true}) b.ReportAllocs() b.ResetTimer() @@ -97,8 +96,7 @@ func BenchmarkThreeFields_WithCaller(b *testing.B) { } func BenchmarkNoField_WithColor(b *testing.B) { - logger := logf.New(io.Discard) - logger.SetColorOutput(true) + logger := logf.New(logf.Opts{Writer: io.Discard, EnableColor: true}) b.ReportAllocs() b.ResetTimer() @@ -110,8 +108,7 @@ func BenchmarkNoField_WithColor(b *testing.B) { } func BenchmarkOneField_WithColor(b *testing.B) { - logger := logf.New(io.Discard) - logger.SetColorOutput(true) + logger := logf.New(logf.Opts{Writer: io.Discard, EnableColor: true}) b.ReportAllocs() b.ResetTimer() b.RunParallel(func(p *testing.PB) { @@ -122,8 +119,7 @@ func BenchmarkOneField_WithColor(b *testing.B) { } func BenchmarkThreeFields_WithColor(b *testing.B) { - logger := logf.New(io.Discard) - logger.SetColorOutput(true) + logger := logf.New(logf.Opts{Writer: io.Discard, EnableColor: true}) b.ReportAllocs() b.ResetTimer() @@ -137,8 +133,7 @@ func BenchmarkThreeFields_WithColor(b *testing.B) { } func BenchmarkErrorField_WithColor(b *testing.B) { - logger := logf.New(io.Discard) - logger.SetColorOutput(true) + logger := logf.New(logf.Opts{Writer: io.Discard, EnableColor: true}) b.ReportAllocs() b.ResetTimer() @@ -152,8 +147,7 @@ func BenchmarkErrorField_WithColor(b *testing.B) { } func BenchmarkHugePayload_WithColor(b *testing.B) { - logger := logf.New(io.Discard) - logger.SetColorOutput(true) + logger := logf.New(logf.Opts{Writer: io.Discard, EnableColor: true}) b.ReportAllocs() b.ResetTimer() diff --git a/examples/main.go b/examples/main.go index a13894d..15a3140 100644 --- a/examples/main.go +++ b/examples/main.go @@ -1,23 +1,22 @@ package main import ( - "os" "time" "github.com/zerodha/logf" ) func main() { - logger := logf.New(os.Stderr) - - // Basic log. + logger := logf.New(logf.Opts{ + EnableColor: true, + Level: logf.DebugLevel, + CallerSkipFrameCount: 3, + EnableCaller: true, + TimestampFormat: time.RFC3339Nano, + }) + + // Basic logs. logger.Info("starting app") - - // Enable colored output. - logger.SetColorOutput(true) - - // Change verbosity on the fly. - logger.SetLevel(logf.DebugLevel) logger.Debug("meant for debugging app") // Add extra keys to the log. @@ -26,11 +25,6 @@ func main() { // Log with error key. logger.Error("error fetching details", "error", "this is a dummy error") - // Enable `caller` field in the log and specify the number of frames to skip to get the caller. - logger.SetCallerFrame(true, 3) - // Change the default timestamp format. - logger.SetTimestampFormat(time.RFC3339Nano) - // Log the error and set exit code as 1. logger.Fatal("goodbye world") } diff --git a/log.go b/log.go index e8d97a6..95de14e 100644 --- a/log.go +++ b/log.go @@ -23,26 +23,31 @@ var ( bufPool byteBufferPool ) +type Opts struct { + Writer io.Writer + Level Level + TimestampFormat string + EnableColor bool + EnableCaller bool + CallerSkipFrameCount int +} + // Logger is the interface for all log operations // related to emitting logs. type Logger struct { - out io.Writer // Output destination. - level Level // Verbosity of logs. - tsFormat string // Timestamp format. - enableColor bool // Colored output. - enableCaller bool // Print caller information. - callerSkipFrameCount int // Number of frames to skip when detecting caller + out io.Writer // Output destination. + Opts } // Severity level of the log. type Level int const ( - DebugLevel Level = iota // 0 - InfoLevel // 1 - WarnLevel // 2 - ErrorLevel // 3 - FatalLevel // 4 + DebugLevel Level = iota + 1 // 1 + InfoLevel // 2 + WarnLevel // 3 + ErrorLevel // 4 + FatalLevel // 5 ) // ANSI escape codes for coloring text in console. @@ -64,20 +69,21 @@ var colorLvlMap = [...]string{ } // New instantiates a logger object. -// It writes to `stderr` as the default and it's non configurable. -func New(out io.Writer) Logger { - // Initialise logger with sane defaults. - if out == nil { - out = os.Stderr +func New(opts Opts) Logger { + // Initialise fallbacks if unspecified by user. + if opts.Writer == nil { + opts.Writer = os.Stderr + } + if opts.TimestampFormat == "" { + opts.TimestampFormat = defaultTSFormat + } + if opts.Level == 0 { + opts.Level = InfoLevel } return Logger{ - out: newSyncWriter(out), - level: InfoLevel, - tsFormat: defaultTSFormat, - enableColor: false, - enableCaller: false, - callerSkipFrameCount: 0, + out: newSyncWriter(opts.Writer), + Opts: opts, } } @@ -124,38 +130,6 @@ func (l Level) String() string { } } -// SetLevel sets the verbosity for logger. -// Verbosity can be dynamically changed by the caller. -func (l Logger) SetLevel(lvl Level) Logger { - l.level = lvl - return l -} - -// SetWriter sets the output writer for the logger -func (l Logger) SetWriter(w io.Writer) Logger { - l.out = &syncWriter{w: w} - return l -} - -// SetTimestampFormat sets the timestamp format for the `timestamp` key. -func (l Logger) SetTimestampFormat(f string) Logger { - l.tsFormat = f - return l -} - -// SetColorOutput enables/disables colored output. -func (l Logger) SetColorOutput(color bool) Logger { - l.enableColor = color - return l -} - -// SetCallerFrame enables/disables the caller source in the log line. -func (l Logger) SetCallerFrame(caller bool, depth int) Logger { - l.enableCaller = caller - l.callerSkipFrameCount = depth - return l -} - // Debug emits a debug log line. func (l Logger) Debug(msg string, fields ...any) { l.handleLog(msg, DebugLevel, fields...) @@ -188,7 +162,7 @@ func (l Logger) Fatal(msg string, fields ...any) { func (l Logger) handleLog(msg string, lvl Level, fields ...any) { // Discard the log if the verbosity is higher. // For eg, if the lvl is `3` (error), but the incoming message is `0` (debug), skip it. - if lvl < l.level { + if lvl < l.Opts.Level { return } @@ -196,12 +170,10 @@ func (l Logger) handleLog(msg string, lvl Level, fields ...any) { buf := bufPool.Get() // Write fixed keys to the buffer before writing user provided ones. - writeTimeToBuf(buf, l.tsFormat, lvl, l.enableColor) - writeToBuf(buf, "level", lvl, lvl, l.enableColor, true) - writeStringToBuf(buf, "message", msg, lvl, l.enableColor, true) + writeTimeToBuf(buf, l.Opts.TimestampFormat, lvl, l.Opts.EnableColor) + writeToBuf(buf, "level", lvl, lvl, l.Opts.EnableColor, true) + writeStringToBuf(buf, "message", msg, lvl, l.Opts.EnableColor, true) - if l.enableCaller { - writeToBuf(buf, "caller", caller(l.callerSkipFrameCount), lvl, l.enableColor, true) } // Format the line as logfmt. @@ -230,7 +202,7 @@ func (l Logger) handleLog(msg string, lvl Level, fields ...any) { val = fields[i] } - writeToBuf(buf, key, val, lvl, l.enableColor, space) + writeToBuf(buf, key, val, lvl, l.Opts.EnableColor, space) count++ } buf.AppendString("\n") diff --git a/log_test.go b/log_test.go index 00dd902..c9a3964 100644 --- a/log_test.go +++ b/log_test.go @@ -3,7 +3,6 @@ package logf import ( "bytes" "errors" - "os" "strconv" "sync" "testing" @@ -38,18 +37,17 @@ func TestLevelParsing(t *testing.T) { } func TestNewLoggerDefault(t *testing.T) { - l := New(os.Stderr) - assert.Equal(t, l.level, InfoLevel, "level is info") - assert.Equal(t, l.enableColor, false, "color output is disabled") - assert.Equal(t, l.enableCaller, false, "caller is disabled") - assert.Equal(t, l.callerSkipFrameCount, 0, "skip frame count is 0") - assert.Equal(t, l.tsFormat, defaultTSFormat, "timestamp format is default") + l := New(Opts{}) + assert.Equal(t, l.Opts.Level, InfoLevel, "level is info") + assert.Equal(t, l.Opts.EnableColor, false, "color output is disabled") + assert.Equal(t, l.Opts.EnableCaller, false, "caller is disabled") + assert.Equal(t, l.Opts.CallerSkipFrameCount, 0, "skip frame count is 0") + assert.Equal(t, l.Opts.TimestampFormat, defaultTSFormat, "timestamp format is default") } func TestLogFormat(t *testing.T) { buf := &bytes.Buffer{} - l := New(buf) - l.SetColorOutput(false) + l := New(Opts{Writer: buf}) // Info log. l.Info("hello world") @@ -70,8 +68,7 @@ func TestLogFormat(t *testing.T) { func TestOddNumberedFields(t *testing.T) { buf := &bytes.Buffer{} - l := New(buf) - l.SetColorOutput(false) + l := New(Opts{Writer: buf}) // Give a odd number of fields. l.Info("hello world", "key1", "val1", "key2") @@ -82,8 +79,7 @@ func TestOddNumberedFields(t *testing.T) { // These test are typically meant to be run with the data race detector. func TestLoggerConcurrency(t *testing.T) { buf := &bytes.Buffer{} - l := New(buf) - l.SetColorOutput(false) + l := New(Opts{Writer: buf}) for _, n := range []int{10, 100, 1000} { wg := sync.WaitGroup{} From edd3c10812571030f415c6b03009443a64ad87e1 Mon Sep 17 00:00:00 2001 From: Karan Sharma Date: Thu, 7 Jul 2022 14:07:45 +0530 Subject: [PATCH 2/2] feat: reduce allocs while getting caller frame count --- log.go | 33 ++++++++++++++++++++++----------- 1 file changed, 22 insertions(+), 11 deletions(-) diff --git a/log.go b/log.go index 95de14e..e0f11aa 100644 --- a/log.go +++ b/log.go @@ -6,7 +6,6 @@ import ( stdlog "log" "os" "runtime" - "strconv" "strings" "sync" "time" @@ -174,6 +173,8 @@ func (l Logger) handleLog(msg string, lvl Level, fields ...any) { writeToBuf(buf, "level", lvl, lvl, l.Opts.EnableColor, true) writeStringToBuf(buf, "message", msg, lvl, l.Opts.EnableColor, true) + if l.Opts.EnableCaller { + writeCallerToBuf(buf, "caller", l.Opts.CallerSkipFrameCount, lvl, l.EnableColor, true) } // Format the line as logfmt. @@ -245,6 +246,26 @@ func writeStringToBuf(buf *byteBuffer, key string, val string, lvl Level, color, } } +func writeCallerToBuf(buf *byteBuffer, key string, depth int, lvl Level, color, space bool) { + _, file, line, ok := runtime.Caller(depth) + if !ok { + file = "???" + line = 0 + } + if color { + buf.AppendString(getColoredKey(key, lvl)) + } else { + buf.AppendString(key) + } + buf.AppendByte('=') + escapeAndWriteString(buf, file) + buf.AppendByte(':') + buf.AppendInt(int64(line)) + if space { + buf.AppendByte(' ') + } +} + // writeToBuf takes key, value and additional options to write to the buffer in logfmt. func writeToBuf(buf *byteBuffer, key string, val any, lvl Level, color, space bool) { if color { @@ -295,16 +316,6 @@ func getColoredKey(k string, lvl Level) string { return colorLvlMap[lvl] + k + reset } -// caller returns the file:line of the caller. -func caller(depth int) string { - _, file, line, ok := runtime.Caller(depth) - if !ok { - file = "???" - line = 0 - } - return file + ":" + strconv.Itoa(line) -} - // checkEscapingRune returns true if the rune is to be escaped. func checkEscapingRune(r rune) bool { return r == '=' || r == ' ' || r == '"' || r == utf8.RuneError