Merge pull request #9 from krombel/useLevelWriterInterface

use zerolog.LevelWriter interface for performance

Author: archdx

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")
 }

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
 	}

writer_test.go

@@ -1,6 +1,8 @@
 package zlogsentry
 
 import (
+	"errors"
+	"io"
 	"testing"
 	"time"
 
@@ -22,6 +24,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)
@@ -35,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 {
@@ -46,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)
@@ -56,3 +180,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_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.WriteLevel(zerolog.ErrorLevel, logEventJSON)
+	}
+}