From 4d539ed43d38be4ff55b9bc32695eccc1fce9e6f Mon Sep 17 00:00:00 2001 From: FishGoddess <1149062639@qq.com> Date: Wed, 13 Dec 2023 21:24:12 +0800 Subject: [PATCH] =?UTF-8?q?=E8=B0=83=E6=95=B4=E8=87=AA=E5=AE=9A=E4=B9=89?= =?UTF-8?q?=E7=9A=84=20handler?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- _examples/performance_test.go | 16 ++ console.go | 206 ------------------------- handler.go | 10 +- standard.go | 226 ++++++++++++++++++++++++++++ console_test.go => standard_test.go | 9 +- 5 files changed, 252 insertions(+), 215 deletions(-) delete mode 100644 console.go create mode 100644 standard.go rename console_test.go => standard_test.go (81%) diff --git a/_examples/performance_test.go b/_examples/performance_test.go index d9dc77a..83ad07b 100644 --- a/_examples/performance_test.go +++ b/_examples/performance_test.go @@ -54,6 +54,22 @@ BenchmarkZapFile-2 382790 2641 ns/op BenchmarkLogrusFile-2 174944 6491 ns/op 2080 B/op 32 allocs/op */ +// go test -v ./_examples/performance_test.go -bench=^BenchmarkLogitLoggerStandardHandler$ -benchtime=1s +func BenchmarkLogitLoggerStandardHandler(b *testing.B) { + logger := logit.NewLogger( + logit.WithInfoLevel(), + logit.WithHandler("standard"), + logit.WithWriter(io.Discard), + ) + + b.ReportAllocs() + b.StartTimer() + + for i := 0; i < b.N; i++ { + logger.Info("info...", "trace", "xxx", "id", 123, "pi", 3.14) + } +} + // go test -v ./_examples/performance_test.go -bench=^BenchmarkLogitLoggerTextHandler$ -benchtime=1s func BenchmarkLogitLoggerTextHandler(b *testing.B) { logger := logit.NewLogger( diff --git a/console.go b/console.go deleted file mode 100644 index 2844c5b..0000000 --- a/console.go +++ /dev/null @@ -1,206 +0,0 @@ -// Copyright 2023 FichGoddess. All Rights Reserved. -// -// Licensed under the Apache License, Version 2.0 (the "License"); -// you may not use this file except in compliance with the License. -// You may obtain a copy of the License at -// -// http://www.apache.org/licenses/LICENSE-2.0 -// -// Unless required by applicable law or agreed to in writing, software -// distributed under the License is distributed on an "AS IS" BASIS, -// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -// See the License for the specific language governing permissions and -// limitations under the License. - -package logit - -import ( - "bytes" - "context" - "io" - "log/slog" - "runtime" - "slices" - "strconv" - "sync" - "time" -) - -const ( - minBufferSize = 1 * 1024 // 1KB - maxBufferSize = 16 * 1024 // 16KB -) - -var ( - attrSeparator = []byte("¦") -) - -var bufferPool = sync.Pool{ - New: func() any { - bs := make([]byte, 0, minBufferSize) - return &bs - }, -} - -func newBuffer() *[]byte { - return bufferPool.Get().(*[]byte) -} - -func freeBuffer(b *[]byte) { - // Return only smaller buffers for reducing peak allocation. - if cap(*b) <= maxBufferSize { - *b = (*b)[:0] - bufferPool.Put(b) - } -} - -type consoleHandler struct { - w io.Writer - opts slog.HandlerOptions - - group string - attrs []slog.Attr - - mu *sync.Mutex -} - -func newConsoleHandler(w io.Writer, opts *slog.HandlerOptions) slog.Handler { - h := &consoleHandler{ - w: w, - group: "-", - mu: &sync.Mutex{}, - } - - if opts != nil { - h.opts = *opts - } - - if h.opts.Level == nil { - h.opts.Level = slog.LevelInfo - } - - return h -} - -func (ch *consoleHandler) Enabled(ctx context.Context, level slog.Level) bool { - return level >= ch.opts.Level.Level() -} - -func (ch *consoleHandler) WithGroup(name string) slog.Handler { - if name == "" { - return ch - } - - h2 := *ch - h2.group = name - - return &h2 -} - -func (ch *consoleHandler) WithAttrs(attrs []slog.Attr) slog.Handler { - if len(attrs) <= 0 { - return ch - } - - h2 := *ch - - h2.attrs = slices.Clip(h2.attrs) - h2.attrs = append(h2.attrs, attrs...) - - return &h2 -} - -func (ch *consoleHandler) Handle(ctx context.Context, record slog.Record) error { - bufferPtr := newBuffer() - buffer := *bufferPtr - - defer func() { - *bufferPtr = buffer - freeBuffer(bufferPtr) - }() - - if !record.Time.IsZero() { - buffer = record.Time.AppendFormat(buffer, time.RFC3339) - buffer = append(buffer, attrSeparator...) - } - - buffer = append(buffer, record.Level.String()...) - buffer = append(buffer, attrSeparator...) - buffer = append(buffer, ch.group...) - buffer = append(buffer, attrSeparator...) - buffer = append(buffer, record.Message...) - buffer = append(buffer, attrSeparator...) - - if record.PC != 0 { - fs := runtime.CallersFrames([]uintptr{record.PC}) - f, _ := fs.Next() - - // Optimize to minimize allocation. - smallBuf := newBuffer() - defer freeBuffer(smallBuf) - - *smallBuf = append(*smallBuf, f.File...) - *smallBuf = append(*smallBuf, ':') - *smallBuf = strconv.AppendInt(*smallBuf, int64(f.Line), 10) - - buffer = ch.appendAttr(buffer, slog.String(slog.SourceKey, string(*smallBuf))) - } - - for _, attr := range ch.attrs { - buffer = ch.appendAttr(buffer, attr) - } - - if record.NumAttrs() > 0 { - record.Attrs(func(attr slog.Attr) bool { - buffer = ch.appendAttr(buffer, attr) - return true - }) - } - - buffer = bytes.TrimSuffix(buffer, attrSeparator) - buffer = append(buffer, '\n') - - ch.mu.Lock() - defer ch.mu.Unlock() - - _, err := ch.w.Write(buffer) - return err -} - -func (ch *consoleHandler) appendAttr(bs []byte, attr slog.Attr) []byte { - // Resolve the Attr's value before doing anything else. - attr.Value = attr.Value.Resolve() - - // Ignore empty Attrs. - if attr.Equal(slog.Attr{}) { - return bs - } - - switch attr.Value.Kind() { - case slog.KindTime: - // Write times in a standard way, without the monotonic time. - bs = append(bs, attr.Key...) - bs = append(bs, '=') - bs = attr.Value.Time().AppendFormat(bs, time.RFC3339) - bs = append(bs, attrSeparator...) - case slog.KindGroup: - attrs := attr.Value.Group() - - // Ignore empty groups. - if len(attrs) == 0 { - return bs - } - - for _, gAttr := range attrs { - gAttr.Key = attr.Key + "." + gAttr.Key - bs = ch.appendAttr(bs, gAttr) - } - default: - bs = append(bs, attr.Key...) - bs = append(bs, '=') - bs = append(bs, attr.Value.String()...) - bs = append(bs, attrSeparator...) - } - - return bs -} diff --git a/handler.go b/handler.go index 75570b5..850ea52 100644 --- a/handler.go +++ b/handler.go @@ -22,15 +22,15 @@ import ( ) const ( - handlerConsole = "console" - handlerText = "text" - handlerJson = "json" + handlerStandard = "standard" + handlerText = "text" + handlerJson = "json" ) var ( newHandlers = map[string]HandlerFunc{ - handlerConsole: func(w io.Writer, opts *slog.HandlerOptions) slog.Handler { - return newConsoleHandler(w, opts) + handlerStandard: func(w io.Writer, opts *slog.HandlerOptions) slog.Handler { + return newStandardHandler(w, opts) }, handlerText: func(w io.Writer, opts *slog.HandlerOptions) slog.Handler { return slog.NewTextHandler(w, opts) diff --git a/standard.go b/standard.go new file mode 100644 index 0000000..3cf0d26 --- /dev/null +++ b/standard.go @@ -0,0 +1,226 @@ +// Copyright 2023 FishGoddess. All Rights Reserved. +// +// Licensed under the Apashe License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apashe.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package logit + +import ( + "bytes" + "context" + "io" + "log/slog" + "runtime" + "strconv" + "sync" +) + +const ( + timeFormat = "2006-01-02 15:04:05.000" +) + +const ( + minBufferSize = 1 * 1024 // 1KB + maxBufferSize = 16 * 1024 // 16KB +) + +const ( + lineBreak = '\n' + KeyValueConnector = '=' + SourceConnector = ':' +) + +var ( + attrNone = []byte("-") + attrSeparator = []byte("¦") +) + +var ( + emptyAttr = slog.Attr{} +) + +var bufferPool = sync.Pool{ + New: func() any { + bs := make([]byte, 0, minBufferSize) + return &bs + }, +} + +func newBuffer() *[]byte { + return bufferPool.Get().(*[]byte) +} + +func freeBuffer(b *[]byte) { + // Return only smaller buffers for reducing peak allocation. + if cap(*b) <= maxBufferSize { + *b = (*b)[:0] + bufferPool.Put(b) + } +} + +type standardHandler struct { + w io.Writer + opts slog.HandlerOptions + + attrsBytes []byte + groupBytes []byte + + lock *sync.Mutex +} + +func newStandardHandler(w io.Writer, opts *slog.HandlerOptions) slog.Handler { + if opts == nil { + opts = &slog.HandlerOptions{ + Level: slog.LevelInfo, + } + } + + handler := &standardHandler{ + w: w, + opts: *opts, + groupBytes: attrNone, + lock: &sync.Mutex{}, + } + + return handler +} + +// WithAttrs returns a new handler with attrs. +func (sh *standardHandler) WithAttrs(attrs []slog.Attr) slog.Handler { + if len(attrs) <= 0 { + return sh + } + + handler := *sh + for _, attr := range attrs { + handler.attrsBytes = sh.appendAttr(handler.attrsBytes, attr) + } + + return &handler +} + +// WithGroup returns a new handler with group. +func (sh *standardHandler) WithGroup(name string) slog.Handler { + if name == "" { + return sh + } + + handler := *sh + handler.groupBytes = []byte(name) + + return &handler +} + +// Enabled reports whether the logger should ignore logs whose level is lower than passed level. +func (sh *standardHandler) Enabled(ctx context.Context, level slog.Level) bool { + return level >= sh.opts.Level.Level() +} + +func (sh *standardHandler) appendAttr(bs []byte, attr slog.Attr) []byte { + // Resolve the Attr's value before doing anything else. + attr.Value = attr.Value.Resolve() + + if attr.Equal(emptyAttr) { + return bs + } + + kind := attr.Value.Kind() + + // Group should append attrs in group. + if kind == slog.KindGroup { + attrs := attr.Value.Group() + + for _, groupAttr := range attrs { + groupAttr.Key = attr.Key + "." + groupAttr.Key + bs = sh.appendAttr(bs, groupAttr) + } + + return bs + } + + // Time format is a spent operation so we use AppendFormat to speed up. + if kind == slog.KindTime { + bs = append(bs, attr.Key...) + bs = append(bs, KeyValueConnector) + bs = attr.Value.Time().AppendFormat(bs, timeFormat) + bs = append(bs, attrSeparator...) + + return bs + } + + // Other kinds can convert to string and append to bs. + bs = append(bs, attr.Key...) + bs = append(bs, KeyValueConnector) + bs = append(bs, attr.Value.String()...) + bs = append(bs, attrSeparator...) + + return bs +} + +func (sh *standardHandler) appendRecord(buffer []byte, record slog.Record) []byte { + if record.Time.IsZero() { + buffer = append(buffer, attrNone...) + buffer = append(buffer, attrSeparator...) + } else { + // TODO optimize time format + buffer = record.Time.AppendFormat(buffer, timeFormat) + buffer = append(buffer, attrSeparator...) + } + + buffer = append(buffer, record.Level.String()...) + buffer = append(buffer, attrSeparator...) + buffer = append(buffer, sh.groupBytes...) + buffer = append(buffer, attrSeparator...) + buffer = append(buffer, record.Message...) + buffer = append(buffer, attrSeparator...) + + if record.PC != 0 { + fs := runtime.CallersFrames([]uintptr{record.PC}) + f, _ := fs.Next() + + buffer = append(buffer, slog.SourceKey...) + buffer = append(buffer, KeyValueConnector) + buffer = append(buffer, f.File...) + buffer = append(buffer, SourceConnector) + buffer = strconv.AppendInt(buffer, int64(f.Line), 10) + buffer = append(buffer, attrSeparator...) + } + + buffer = append(buffer, sh.attrsBytes...) + + if record.NumAttrs() > 0 { + record.Attrs(func(attr slog.Attr) bool { + buffer = sh.appendAttr(buffer, attr) + return true + }) + } + + buffer = bytes.TrimSuffix(buffer, attrSeparator) + buffer = append(buffer, lineBreak) + + return buffer +} + +// Handle handles one record and returns an error if failed. +func (sh *standardHandler) Handle(ctx context.Context, record slog.Record) error { + buffer := newBuffer() + defer freeBuffer(buffer) + + // Encode record to bytes and append them to buffer. + *buffer = sh.appendRecord(*buffer, record) + + sh.lock.Lock() + defer sh.lock.Unlock() + + _, err := sh.w.Write(*buffer) + return err +} diff --git a/console_test.go b/standard_test.go similarity index 81% rename from console_test.go rename to standard_test.go index 9ca9165..12788b8 100644 --- a/console_test.go +++ b/standard_test.go @@ -17,15 +17,16 @@ package logit import ( "log/slog" "testing" + "time" ) -// go test -v -cover -count=1 -test.cpu=1 -run=^TestConsoleHandler$ -func TestConsoleHandler(t *testing.T) { - logger1 := NewLogger(WithHandler("console")).With("id", 123456) +// go test -v -cover -count=1 -test.cpu=1 -run=^TestStandardHandler$ +func TestStandardHandler(t *testing.T) { + logger1 := NewLogger(WithHandler(handlerStandard)).With("id", 123456) logger1.Info("using console handler 1", slog.Group("log_group1", "k1", 666)) logger2 := logger1.WithGroup("group2").With("name", "fishgoddess") - logger2.Info("using console handler 2", slog.Group("log_group2", "k2", 888)) + logger2.Info("using console handler 2", slog.Group("log_group2", "k2", 888), "t", time.Now()) logger1.Info("using console handler 1", slog.Group("log_group1", "k1", 666)) }