Improve formatter performance (#80)

Author: instabledesign

Makefile

@@ -1,5 +1,5 @@
 test:
-	go test --race -gcflags=-l ./...
+	go test --race -count=1 -v -gcflags=-l ./...
 
 bench:
-	go test -bench=. -gcflags=-l ./...
+	go test -bench=. -count=1 -v -gcflags=-l ./...

benchmark_test.go

@@ -68,7 +68,7 @@ func getEntries() []logger.Entry {
 	}
 }
 
-func BenchmarkMiddleware(b *testing.B) {
+func BenchmarkLoggerWithMiddleware(b *testing.B) {
 	for _, entry := range getEntries() {
 		for _, m := range loggersToBench() {
 			b.Run(m.name+"_"+entry.Message, func(b *testing.B) {

context.go

@@ -1,7 +1,7 @@
 package logger
 
 import (
-	"strings"
+	"github.com/valyala/bytebufferpool"
 )
 
 // Context contain all contextual log data
@@ -59,22 +59,22 @@ func (c *Context) ByteString(name string, value []byte) *Context {
 	return c.SetField(ByteString(name, value))
 }
 
-func (c *Context) stringTo(builder *strings.Builder) *Context {
+func (c *Context) StringTo(byteBuffer *bytebufferpool.ByteBuffer) *Context {
 	if len(*c) == 0 {
-		builder.WriteString("nil")
+		byteBuffer.WriteString("<nil>")
 		return c
 	}
-	i := 0
+	first := true
 	for name, field := range *c {
-		if i != 0 {
-			builder.WriteString(" ")
+		if !first {
+			byteBuffer.WriteString(" ")
 		}
-		builder.WriteString("<")
-		builder.WriteString(name)
-		builder.WriteString(":")
-		builder.WriteString(field.String())
-		builder.WriteString(">")
-		i++
+		byteBuffer.WriteString("<")
+		byteBuffer.WriteString(name)
+		byteBuffer.WriteString(":")
+		byteBuffer.WriteString(field.String())
+		byteBuffer.WriteString(">")
+		first = false
 	}
 	return c
 }
@@ -93,19 +93,22 @@ func (c *Context) String() string {
 	if c == nil || len(*c) == 0 {
 		return "<nil>"
 	}
-	builder := &strings.Builder{}
-	c.stringTo(builder)
-	return builder.String()
+	byteBuffer := bytebufferpool.Get()
+	defer bytebufferpool.Put(byteBuffer)
+	c.StringTo(byteBuffer)
+	return byteBuffer.String()
 }
 
 // GoString was called by fmt.Printf("%#v", context)
 // fmt GoStringer interface
 func (c *Context) GoString() string {
-	builder := &strings.Builder{}
-	builder.WriteString("logger.context[")
-	c.stringTo(builder)
-	builder.WriteString("]")
-	return builder.String()
+	byteBuffer := bytebufferpool.Get()
+	defer bytebufferpool.Put(byteBuffer)
+
+	byteBuffer.WriteString("logger.context[")
+	c.StringTo(byteBuffer)
+	byteBuffer.WriteString("]")
+	return byteBuffer.String()
 }
 
 // Ctx will create a new context with given value

entry.go

@@ -1,7 +1,7 @@
 package logger
 
 import (
-	"strings"
+	"github.com/valyala/bytebufferpool"
 )
 
 // Entry represents a log in its entirety
@@ -14,20 +14,22 @@ type Entry struct {
 
 // String will return Entry as string
 func (e *Entry) String() string {
-	builder := &strings.Builder{}
-	EntryToString(*e, builder)
-	return builder.String()
+	byteBuffer := bytebufferpool.Get()
+	defer bytebufferpool.Put(byteBuffer)
+
+	EntryToString(*e, byteBuffer)
+	return byteBuffer.String()
 }
 
-// EntryToString will write entry as string in builder
-func EntryToString(entry Entry, builder *strings.Builder) {
-	builder.WriteString("<")
-	builder.WriteString(entry.Level.String())
-	builder.WriteString("> ")
-	builder.WriteString(entry.Message)
+// EntryToString will write entry as string in byteBuffer
+func EntryToString(entry Entry, byteBuffer *bytebufferpool.ByteBuffer) {
+	byteBuffer.WriteString(`<`)
+	entry.Level.StringTo(byteBuffer)
+	byteBuffer.WriteString(`> `)
+	byteBuffer.WriteString(entry.Message)
 	if entry.Context != nil {
-		builder.WriteString(" [ ")
-		builder.WriteString(entry.Context.String())
-		builder.WriteString(" ]")
+		byteBuffer.WriteString(` [ `)
+		entry.Context.StringTo(byteBuffer)
+		byteBuffer.WriteString(` ]`)
 	}
 }

entry_test.go

@@ -1,7 +1,7 @@
 package logger_test
 
 import (
-	"strings"
+	"github.com/valyala/bytebufferpool"
 	"testing"
 
 	"github.com/stretchr/testify/assert"
@@ -43,10 +43,12 @@ func TestEntryToString(t *testing.T) {
 
 	for _, tt := range tests {
 		t.Run(tt.name, func(t *testing.T) {
-			builder := &strings.Builder{}
-			logger.EntryToString(tt.entry, builder)
+			byteBuffer := bytebufferpool.Get()
+			defer bytebufferpool.Put(byteBuffer)
+
+			logger.EntryToString(tt.entry, byteBuffer)
 			for _, s := range tt.strings {
-				assert.Contains(t, builder.String(), s)
+				assert.Contains(t, byteBuffer.String(), s)
 			}
 		})
 	}

field.go

@@ -3,8 +3,8 @@ package logger
 import (
 	"encoding/json"
 	"fmt"
+	"github.com/valyala/bytebufferpool"
 	"strconv"
-	"strings"
 	"time"
 )
 
@@ -126,15 +126,17 @@ func (f *Field) MarshalJSON() ([]byte, error) {
 // GoString was called by fmt.Printf("%#v", Fields)
 // fmt GoStringer interface
 func (f *Field) GoString() string {
-	builder := &strings.Builder{}
-	builder.WriteString("logger.Field{Name: ")
-	builder.WriteString(f.Name)
-	builder.WriteString(", Value: ")
-	builder.WriteString(f.String())
-	builder.WriteString(", Type: ")
-	builder.WriteString(strconv.FormatUint(uint64(f.Type), 10))
-	builder.WriteString("}")
-	return builder.String()
+	byteBuffer := bytebufferpool.Get()
+	defer bytebufferpool.Put(byteBuffer)
+
+	byteBuffer.WriteString("logger.Field{Name: ")
+	byteBuffer.WriteString(f.Name)
+	byteBuffer.WriteString(", Value: ")
+	byteBuffer.WriteString(f.String())
+	byteBuffer.WriteString(", Type: ")
+	byteBuffer.WriteString(strconv.FormatUint(uint64(f.Type), 10))
+	byteBuffer.WriteString("}")
+	return byteBuffer.String()
 }
 
 // Skip will create Skip Field

fields.go

@@ -1,7 +1,7 @@
 package logger
 
 import (
-	"strings"
+	"github.com/valyala/bytebufferpool"
 )
 
 // Fields was slice format of Fields
@@ -33,42 +33,45 @@ func (f *Fields) ByteString(name string, value []byte) *Fields {
 	return f.SetField(ByteString(name, value))
 }
 
-func (f *Fields) stringTo(builder *strings.Builder) *Fields {
+func (f *Fields) StringTo(byteBuffer *bytebufferpool.ByteBuffer) {
 	if len(*f) == 0 {
-		builder.WriteString(" ")
-		return f
+		byteBuffer.WriteString(" ")
+		return
 	}
-	i := 0
+	first := true
 	for _, field := range *f {
-		if i != 0 {
-			builder.WriteString(" ")
+		if !first {
+			byteBuffer.WriteString(" ")
 		}
-		builder.WriteString("<")
-		builder.WriteString(field.Name)
-		builder.WriteString(":")
-		builder.WriteString(field.String())
-		builder.WriteString(">")
-		i++
+		byteBuffer.WriteString("<")
+		byteBuffer.WriteString(field.Name)
+		byteBuffer.WriteString(":")
+		byteBuffer.WriteString(field.String())
+		byteBuffer.WriteString(">")
+		first = false
 	}
-	return f
-
+	return
 }
 
 // String will return Fields as string
 func (f *Fields) String() string {
-	builder := &strings.Builder{}
-	f.stringTo(builder)
-	return builder.String()
+	byteBuffer := bytebufferpool.Get()
+	defer bytebufferpool.Put(byteBuffer)
+
+	f.StringTo(byteBuffer)
+	return byteBuffer.String()
 }
 
 // GoString was called by fmt.Printf("%#v", Fields)
 // fmt GoStringer interface
 func (f *Fields) GoString() string {
-	builder := &strings.Builder{}
-	builder.WriteString("logger.Fields[")
-	f.stringTo(builder)
-	builder.WriteString("]")
-	return builder.String()
+	byteBuffer := bytebufferpool.Get()
+	defer bytebufferpool.Put(byteBuffer)
+
+	byteBuffer.WriteString("logger.Fields[")
+	f.StringTo(byteBuffer)
+	byteBuffer.WriteString("]")
+	return byteBuffer.String()
 }
 
 // NewFields will create a Fields collection with initial value

formatter/default.go

@@ -1,9 +1,8 @@
 package formatter
 
 import (
-	"strings"
-
 	"github.com/gol4ng/logger"
+	"github.com/valyala/bytebufferpool"
 )
 
 var falseCondition = func(entry logger.Entry) bool {
@@ -18,60 +17,54 @@ type DefaultFormatter struct {
 
 // Format will return Entry as string
 func (n *DefaultFormatter) Format(entry logger.Entry) string {
-	n.init()
-	builder := &strings.Builder{}
+	byteBuffer := bytebufferpool.Get()
+	defer bytebufferpool.Put(byteBuffer)
 
 	colored := n.colored(entry)
 	if colored {
 		switch entry.Level {
 		case logger.DebugLevel:
-			builder.WriteString("\x1b[1;36m")
+			byteBuffer.WriteString("\x1b[1;36m")
 		case logger.InfoLevel:
-			builder.WriteString("\x1b[1;32m")
+			byteBuffer.WriteString("\x1b[1;32m")
 		case logger.NoticeLevel:
-			builder.WriteString("\x1b[1;34m")
+			byteBuffer.WriteString("\x1b[1;34m")
 		case logger.WarningLevel:
-			builder.WriteString("\x1b[1;33m")
+			byteBuffer.WriteString("\x1b[1;33m")
 		case logger.ErrorLevel:
-			builder.WriteString("\x1b[1;31m")
+			byteBuffer.WriteString("\x1b[1;31m")
 		case logger.CriticalLevel:
-			builder.WriteString("\x1b[1;30;47m")
+			byteBuffer.WriteString("\x1b[1;30;47m")
 		case logger.AlertLevel:
-			builder.WriteString("\x1b[1;30;43m")
+			byteBuffer.WriteString("\x1b[1;30;43m")
 		case logger.EmergencyLevel:
-			builder.WriteString("\x1b[1;37;41m")
+			byteBuffer.WriteString("\x1b[1;37;41m")
 		}
 	}
 
-	builder.WriteString("<")
-	builder.WriteString(entry.Level.String())
-	builder.WriteString(">")
+	byteBuffer.WriteString(`<`)
+	byteBuffer.WriteString(entry.Level.String())
+	byteBuffer.WriteString(`>`)
 	if colored {
-		builder.WriteString("\x1b[m")
+		byteBuffer.WriteString("\x1b[m")
 	}
 	if entry.Message != "" {
-		builder.WriteString(" ")
-		builder.WriteString(entry.Message)
+		byteBuffer.WriteString(` `)
+		byteBuffer.WriteString(entry.Message)
 	}
 	if entry.Context != nil && n.displayContext(entry) {
-		builder.WriteString(" ")
-		ContextToJSON(entry.Context, builder)
-	}
-	return builder.String()
-}
-
-func (n *DefaultFormatter) init() {
-	if n.colored == nil {
-		n.colored = falseCondition
-	}
-	if n.displayContext == nil {
-		n.displayContext = falseCondition
+		byteBuffer.WriteString(` `)
+		ContextToJSON(entry.Context, byteBuffer)
 	}
+	return byteBuffer.String()
 }
 
 // NewDefaultFormatter will create a new DefaultFormatter
 func NewDefaultFormatter(options ...Option) *DefaultFormatter {
-	f := &DefaultFormatter{}
+	f := &DefaultFormatter{
+		colored: falseCondition,
+		displayContext: falseCondition,
+	}
 	for _, option := range options {
 		option(f)
 	}

formatter/default_test.go

@@ -16,7 +16,6 @@ func TestDefaultFormatter_Format(t *testing.T) {
 		entry     logger.Entry
 		expected  string
 	}{
-		{name: "test default formatter struct", formatter: &formatter.DefaultFormatter{}, entry: logger.Entry{}, expected: "<emergency>"},
 		{name: "test NewDefaultFormatter()", formatter: formatter.NewDefaultFormatter(), entry: logger.Entry{}, expected: "<emergency>"},
 		{
 			name:      "test NewDefaultFormatter(formatter.WithContext(true)",