From 6fe949d569186cc339b473f2fc79f2916df7d3cb Mon Sep 17 00:00:00 2001 From: Matthias Kesler Date: Wed, 21 Jun 2023 16:51:00 +0200 Subject: [PATCH 1/2] use zerolog.LevelWriter interface to skip parsing log if level should not be logged --- README.md | 4 +-- writer.go | 67 +++++++++++++++++++++++++++++++++----------------- writer_test.go | 47 +++++++++++++++++++++++++++++++++++ 3 files changed, 93 insertions(+), 25 deletions(-) diff --git a/README.md b/README.md index e459c10..2ccd87a 100644 --- a/README.md +++ b/README.md @@ -6,7 +6,6 @@ ```go import ( "errors" - "io" stdlog "log" "os" @@ -22,7 +21,8 @@ func main() { defer w.Close() - logger := zerolog.New(io.MultiWriter(w, os.Stdout)).With().Timestamp().Logger() + multi := zerolog.MultiLevelWriter(os.Stdout, w) + logger := zerolog.New(multi).With().Timestamp().Logger() logger.Error().Err(errors.New("dial timeout")).Msg("test message") } diff --git a/writer.go b/writer.go index 886762b..426216a 100644 --- a/writer.go +++ b/writer.go @@ -33,8 +33,21 @@ type Writer struct { } // Write handles zerolog's json and sends events to sentry. -func (w *Writer) Write(data []byte) (int, error) { +func (w *Writer) Write(data []byte) (n int, err error) { + n = len(data) + + lvl, err := w.parseLogLevel(data) + if err != nil { + return n, nil + } + + if _, enabled := w.levels[lvl]; !enabled { + return + } + event, ok := w.parseLogEvent(data) + event.Level = levelsMapping[lvl] + if ok { w.hub.CaptureEvent(event) // should flush before os.Exit @@ -43,7 +56,27 @@ func (w *Writer) Write(data []byte) (int, error) { } } - return len(data), nil + return +} + +// implements zerolog.LevelWriter +func (w *Writer) WriteLevel(level zerolog.Level, p []byte) (n int, err error) { + n = len(p) + if _, enabled := w.levels[level]; !enabled { + return + } + + event, ok := w.parseLogEvent(p) + event.Level = levelsMapping[level] + + if ok { + w.hub.CaptureEvent(event) + // should flush before os.Exit + if event.Level == sentry.LevelFatal { + w.hub.Flush(w.flushTimeout) + } + } + return } // Close forces client to flush all pending events. @@ -53,37 +86,27 @@ func (w *Writer) Close() error { return nil } -func (w *Writer) parseLogEvent(data []byte) (*sentry.Event, bool) { - const logger = "zerolog" - +// parses the log level from the encoded log +func (w *Writer) parseLogLevel(data []byte) (zerolog.Level, error) { lvlStr, err := jsonparser.GetUnsafeString(data, zerolog.LevelFieldName) if err != nil { - return nil, false - } - - lvl, err := zerolog.ParseLevel(lvlStr) - if err != nil { - return nil, false + return zerolog.Disabled, nil } - _, enabled := w.levels[lvl] - if !enabled { - return nil, false - } + return zerolog.ParseLevel(lvlStr) +} - sentryLvl, ok := levelsMapping[lvl] - if !ok { - return nil, false - } +// parses the event except the log level +func (w *Writer) parseLogEvent(data []byte) (*sentry.Event, bool) { + const logger = "zerolog" event := sentry.Event{ Timestamp: now(), - Level: sentryLvl, Logger: logger, Extra: map[string]interface{}{}, } - err = jsonparser.ObjectEach(data, func(key, value []byte, vt jsonparser.ValueType, offset int) error { + err := jsonparser.ObjectEach(data, func(key, value []byte, vt jsonparser.ValueType, offset int) error { switch string(key) { case zerolog.MessageFieldName: event.Message = bytesToStrUnsafe(value) @@ -99,7 +122,6 @@ func (w *Writer) parseLogEvent(data []byte) (*sentry.Event, bool) { return nil }) - if err != nil { return nil, false } @@ -296,7 +318,6 @@ func New(dsn string, opts ...WriterOption) (*Writer, error) { BeforeSend: cfg.beforeSend, TracesSampleRate: cfg.tracesSampleRate, }) - if err != nil { return nil, err } diff --git a/writer_test.go b/writer_test.go index 803ff9b..20a157b 100644 --- a/writer_test.go +++ b/writer_test.go @@ -22,6 +22,9 @@ func TestParseLogEvent(t *testing.T) { ev, ok := w.parseLogEvent(logEventJSON) require.True(t, ok) + zLevel, err := w.parseLogLevel(logEventJSON) + assert.Nil(t, err) + ev.Level = levelsMapping[zLevel] assert.Equal(t, ts, ev.Timestamp) assert.Equal(t, sentry.LevelError, ev.Level) @@ -56,3 +59,47 @@ func BenchmarkParseLogEvent_DisabledLevel(b *testing.B) { w.parseLogEvent(logEventJSON) } } + +func BenchmarkWriteLogEvent(b *testing.B) { + w, err := New("") + if err != nil { + b.Errorf("failed to create writer: %v", err) + } + + for i := 0; i < b.N; i++ { + _, _ = w.Write(logEventJSON) + } +} + +func BenchmarkWriteLogEvent_Disabled(b *testing.B) { + w, err := New("", WithLevels(zerolog.FatalLevel)) + if err != nil { + b.Errorf("failed to create writer: %v", err) + } + + for i := 0; i < b.N; i++ { + _, _ = w.Write(logEventJSON) + } +} + +func BenchmarkWriteLogLevelEvent(b *testing.B) { + w, err := New("") + if err != nil { + b.Errorf("failed to create writer: %v", err) + } + + for i := 0; i < b.N; i++ { + _, _ = w.WriteLevel(zerolog.ErrorLevel, logEventJSON) + } +} + +func BenchmarkWriteLogLevelEvent_DisabledLevel(b *testing.B) { + w, err := New("", WithLevels(zerolog.FatalLevel)) + if err != nil { + b.Errorf("failed to create writer: %v", err) + } + + for i := 0; i < b.N; i++ { + _, _ = w.WriteLevel(zerolog.ErrorLevel, logEventJSON) + } +} From e81a73f78b3891e255f157f6d7a66ba68c8e26c9 Mon Sep 17 00:00:00 2001 From: Matthias Kesler Date: Mon, 26 Jun 2023 20:16:18 +0200 Subject: [PATCH 2/2] add tests --- writer_test.go | 125 ++++++++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 123 insertions(+), 2 deletions(-) diff --git a/writer_test.go b/writer_test.go index 20a157b..27b5625 100644 --- a/writer_test.go +++ b/writer_test.go @@ -1,6 +1,8 @@ package zlogsentry import ( + "errors" + "io" "testing" "time" @@ -38,6 +40,125 @@ func TestParseLogEvent(t *testing.T) { assert.Equal(t, "bee07485-2485-4f64-99e1-d10165884ca7", ev.Extra["requestId"]) } +func TestParseLogLevel(t *testing.T) { + w, err := New("") + require.Nil(t, err) + + level, err := w.parseLogLevel(logEventJSON) + require.Nil(t, err) + assert.Equal(t, zerolog.ErrorLevel, level) +} + +func TestWrite(t *testing.T) { + beforeSendCalled := false + writer, err := New("", WithBeforeSend(func(event *sentry.Event, hint *sentry.EventHint) *sentry.Event { + assert.Equal(t, sentry.LevelError, event.Level) + assert.Equal(t, "test message", event.Message) + require.Len(t, event.Exception, 1) + assert.Equal(t, "dial timeout", event.Exception[0].Value) + assert.True(t, time.Since(event.Timestamp).Minutes() < 1) + assert.Equal(t, "bee07485-2485-4f64-99e1-d10165884ca7", event.Extra["requestId"]) + beforeSendCalled = true + return event + })) + require.Nil(t, err) + + var zerologError error + zerolog.ErrorHandler = func(err error) { + zerologError = err + } + + // use io.MultiWriter to enforce using the Write() method + log := zerolog.New(io.MultiWriter(writer)).With().Timestamp(). + Str("requestId", "bee07485-2485-4f64-99e1-d10165884ca7"). + Logger() + log.Err(errors.New("dial timeout")). + Msg("test message") + + require.Nil(t, zerologError) + require.True(t, beforeSendCalled) +} + +func TestWriteLevel(t *testing.T) { + beforeSendCalled := false + writer, err := New("", WithBeforeSend(func(event *sentry.Event, hint *sentry.EventHint) *sentry.Event { + assert.Equal(t, sentry.LevelError, event.Level) + assert.Equal(t, "test message", event.Message) + require.Len(t, event.Exception, 1) + assert.Equal(t, "dial timeout", event.Exception[0].Value) + assert.True(t, time.Since(event.Timestamp).Minutes() < 1) + assert.Equal(t, "bee07485-2485-4f64-99e1-d10165884ca7", event.Extra["requestId"]) + beforeSendCalled = true + return event + })) + require.Nil(t, err) + + var zerologError error + zerolog.ErrorHandler = func(err error) { + zerologError = err + } + + log := zerolog.New(writer).With().Timestamp(). + Str("requestId", "bee07485-2485-4f64-99e1-d10165884ca7"). + Logger() + log.Err(errors.New("dial timeout")). + Msg("test message") + + require.Nil(t, zerologError) + require.True(t, beforeSendCalled) +} + +func TestWrite_Disabled(t *testing.T) { + beforeSendCalled := false + writer, err := New("", + WithLevels(zerolog.FatalLevel), + WithBeforeSend(func(event *sentry.Event, hint *sentry.EventHint) *sentry.Event { + beforeSendCalled = true + return event + })) + require.Nil(t, err) + + var zerologError error + zerolog.ErrorHandler = func(err error) { + zerologError = err + } + + // use io.MultiWriter to enforce using the Write() method + log := zerolog.New(io.MultiWriter(writer)).With().Timestamp(). + Str("requestId", "bee07485-2485-4f64-99e1-d10165884ca7"). + Logger() + log.Err(errors.New("dial timeout")). + Msg("test message") + + require.Nil(t, zerologError) + require.False(t, beforeSendCalled) +} + +func TestWriteLevel_Disabled(t *testing.T) { + beforeSendCalled := false + writer, err := New("", + WithLevels(zerolog.FatalLevel), + WithBeforeSend(func(event *sentry.Event, hint *sentry.EventHint) *sentry.Event { + beforeSendCalled = true + return event + })) + require.Nil(t, err) + + var zerologError error + zerolog.ErrorHandler = func(err error) { + zerologError = err + } + + log := zerolog.New(writer).With().Timestamp(). + Str("requestId", "bee07485-2485-4f64-99e1-d10165884ca7"). + Logger() + log.Err(errors.New("dial timeout")). + Msg("test message") + + require.Nil(t, zerologError) + require.False(t, beforeSendCalled) +} + func BenchmarkParseLogEvent(b *testing.B) { w, err := New("") if err != nil { @@ -49,7 +170,7 @@ func BenchmarkParseLogEvent(b *testing.B) { } } -func BenchmarkParseLogEvent_DisabledLevel(b *testing.B) { +func BenchmarkParseLogEvent_Disabled(b *testing.B) { w, err := New("", WithLevels(zerolog.FatalLevel)) if err != nil { b.Errorf("failed to create writer: %v", err) @@ -93,7 +214,7 @@ func BenchmarkWriteLogLevelEvent(b *testing.B) { } } -func BenchmarkWriteLogLevelEvent_DisabledLevel(b *testing.B) { +func BenchmarkWriteLogLevelEvent_Disabled(b *testing.B) { w, err := New("", WithLevels(zerolog.FatalLevel)) if err != nil { b.Errorf("failed to create writer: %v", err)