From 582b572a1f1f574654b5db5ea6d65f9244ae5ccd Mon Sep 17 00:00:00 2001 From: Sarat Chandra Date: Mon, 27 Jun 2022 17:35:13 +0530 Subject: [PATCH] fix: Fix panic incase of concurrent colored loggging. Also changed benchmarks to run parallelly. --- benchmark_test.go | 181 ++++++++++++++++++++++++++-------------------- log.go | 19 +---- 2 files changed, 106 insertions(+), 94 deletions(-) diff --git a/benchmark_test.go b/benchmark_test.go index 44ef36a..9a972bc 100644 --- a/benchmark_test.go +++ b/benchmark_test.go @@ -13,9 +13,11 @@ func BenchmarkNoField(b *testing.B) { logger.SetWriter(io.Discard) b.ReportAllocs() b.ResetTimer() - for i := 0; i < b.N; i++ { - logger.Info("hello world") - } + b.RunParallel(func(p *testing.PB) { + for p.Next() { + logger.Info("hello world") + } + }) } func BenchmarkOneField(b *testing.B) { @@ -23,9 +25,11 @@ func BenchmarkOneField(b *testing.B) { logger.SetWriter(io.Discard) b.ReportAllocs() b.ResetTimer() - for i := 0; i < b.N; i++ { - logger.WithFields(logf.Fields{"stack": "testing"}).Info("hello world") - } + b.RunParallel(func(p *testing.PB) { + for p.Next() { + logger.WithFields(logf.Fields{"stack": "testing"}).Info("hello world") + } + }) } func BenchmarkThreeFields(b *testing.B) { @@ -34,13 +38,15 @@ func BenchmarkThreeFields(b *testing.B) { b.ReportAllocs() b.ResetTimer() - for i := 0; i < b.N; i++ { - logger.WithFields(logf.Fields{ - "component": "api", - "method": "GET", - "bytes": 1 << 18, - }).Info("request completed") - } + b.RunParallel(func(p *testing.PB) { + for p.Next() { + logger.WithFields(logf.Fields{ + "component": "api", + "method": "GET", + "bytes": 1 << 18, + }).Info("request completed") + } + }) } func BenchmarkThreeFields_WithCaller(b *testing.B) { @@ -50,13 +56,15 @@ func BenchmarkThreeFields_WithCaller(b *testing.B) { b.ReportAllocs() b.ResetTimer() - for i := 0; i < b.N; i++ { - logger.WithFields(logf.Fields{ - "component": "api", - "method": "GET", - "bytes": 1 << 18, - }).Info("request completed") - } + b.RunParallel(func(p *testing.PB) { + for p.Next() { + logger.WithFields(logf.Fields{ + "component": "api", + "method": "GET", + "bytes": 1 << 18, + }).Info("request completed") + } + }) } func BenchmarkErrorField(b *testing.B) { @@ -67,9 +75,11 @@ func BenchmarkErrorField(b *testing.B) { fakeErr := errors.New("fake error") - for i := 0; i < b.N; i++ { - logger.WithError(fakeErr).Error("request failed") - } + b.RunParallel(func(p *testing.PB) { + for p.Next() { + logger.WithError(fakeErr).Error("request failed") + } + }) } func BenchmarkHugePayload(b *testing.B) { @@ -78,26 +88,28 @@ func BenchmarkHugePayload(b *testing.B) { b.ReportAllocs() b.ResetTimer() - for i := 0; i < b.N; i++ { - logger.WithFields(logf.Fields{ - "id": 11, - "title": "perfume Oil", - "description": "Mega Discount, Impression of A...", - "price": 13, - "discountPercentage": 8.4, - "rating": 4.26, - "stock": 65, - "brand": "Impression of Acqua Di Gio", - "category": "fragrances", - "thumbnail": "https://dummyjson.com/image/i/products/11/thumbnail.jpg", - "images": []string{ - "https://dummyjson.com/image/i/products/11/1.jpg", - "https://dummyjson.com/image/i/products/11/2.jpg", - "https://dummyjson.com/image/i/products/11/3.jpg", - "https://dummyjson.com/image/i/products/11/thumbnail.jpg", - }, - }).Info("fetched details") - } + b.RunParallel(func(p *testing.PB) { + for p.Next() { + logger.WithFields(logf.Fields{ + "id": 11, + "title": "perfume Oil", + "description": "Mega Discount, Impression of A...", + "price": 13, + "discountPercentage": 8.4, + "rating": 4.26, + "stock": 65, + "brand": "Impression of Acqua Di Gio", + "category": "fragrances", + "thumbnail": "https://dummyjson.com/image/i/products/11/thumbnail.jpg", + "images": []string{ + "https://dummyjson.com/image/i/products/11/1.jpg", + "https://dummyjson.com/image/i/products/11/2.jpg", + "https://dummyjson.com/image/i/products/11/3.jpg", + "https://dummyjson.com/image/i/products/11/thumbnail.jpg", + }, + }).Info("fetched details") + } + }) } func BenchmarkNoField_WithColor(b *testing.B) { @@ -106,9 +118,12 @@ func BenchmarkNoField_WithColor(b *testing.B) { logger.SetColorOutput(true) b.ReportAllocs() b.ResetTimer() - for i := 0; i < b.N; i++ { - logger.Info("hello world") - } + + b.RunParallel(func(p *testing.PB) { + for p.Next() { + logger.Info("hello world") + } + }) } func BenchmarkOneField_WithColor(b *testing.B) { @@ -117,9 +132,11 @@ func BenchmarkOneField_WithColor(b *testing.B) { logger.SetColorOutput(true) b.ReportAllocs() b.ResetTimer() - for i := 0; i < b.N; i++ { - logger.WithFields(logf.Fields{"stack": "testing"}).Info("hello world") - } + b.RunParallel(func(p *testing.PB) { + for p.Next() { + logger.WithFields(logf.Fields{"stack": "testing"}).Info("hello world") + } + }) } func BenchmarkThreeFields_WithColor(b *testing.B) { @@ -129,13 +146,15 @@ func BenchmarkThreeFields_WithColor(b *testing.B) { b.ReportAllocs() b.ResetTimer() - for i := 0; i < b.N; i++ { - logger.WithFields(logf.Fields{ - "component": "api", - "method": "GET", - "bytes": 1 << 18, - }).Info("request completed") - } + b.RunParallel(func(p *testing.PB) { + for p.Next() { + logger.WithFields(logf.Fields{ + "component": "api", + "method": "GET", + "bytes": 1 << 18, + }).Info("request completed") + } + }) } func BenchmarkHugePayload_WithColor(b *testing.B) { @@ -145,26 +164,28 @@ func BenchmarkHugePayload_WithColor(b *testing.B) { b.ReportAllocs() b.ResetTimer() - for i := 0; i < b.N; i++ { - logger.WithFields(logf.Fields{ - "id": 11, - "title": "perfume Oil", - "description": "Mega Discount, Impression of A...", - "price": 13, - "discountPercentage": 8.4, - "rating": 4.26, - "stock": 65, - "brand": "Impression of Acqua Di Gio", - "category": "fragrances", - "thumbnail": "https://dummyjson.com/image/i/products/11/thumbnail.jpg", - "images": []string{ - "https://dummyjson.com/image/i/products/11/1.jpg", - "https://dummyjson.com/image/i/products/11/2.jpg", - "https://dummyjson.com/image/i/products/11/3.jpg", - "https://dummyjson.com/image/i/products/11/thumbnail.jpg", - }, - }).Info("fetched details") - } + b.RunParallel(func(p *testing.PB) { + for p.Next() { + logger.WithFields(logf.Fields{ + "id": 11, + "title": "perfume Oil", + "description": "Mega Discount, Impression of A...", + "price": 13, + "discountPercentage": 8.4, + "rating": 4.26, + "stock": 65, + "brand": "Impression of Acqua Di Gio", + "category": "fragrances", + "thumbnail": "https://dummyjson.com/image/i/products/11/thumbnail.jpg", + "images": []string{ + "https://dummyjson.com/image/i/products/11/1.jpg", + "https://dummyjson.com/image/i/products/11/2.jpg", + "https://dummyjson.com/image/i/products/11/3.jpg", + "https://dummyjson.com/image/i/products/11/thumbnail.jpg", + }, + }).Info("fetched details") + } + }) } func BenchmarkErrorField_WithColor(b *testing.B) { @@ -176,7 +197,9 @@ func BenchmarkErrorField_WithColor(b *testing.B) { fakeErr := errors.New("fake error") - for i := 0; i < b.N; i++ { - logger.WithError(fakeErr).Error("request failed") - } + b.RunParallel(func(p *testing.PB) { + for p.Next() { + logger.WithError(fakeErr).Error("request failed") + } + }) } diff --git a/log.go b/log.go index a163862..ee96cf9 100644 --- a/log.go +++ b/log.go @@ -210,22 +210,11 @@ func (l *Logger) handleLog(msg string, lvl Level) { // Format the line as logfmt. var count int // count is find out if this is the last key in while itering l.fields. for k, v := range l.fields { - if l.enableColor { - // Release the lock because coloring the key is expensive. - l.mu.Unlock() - space := false - if count != len(l.fields)-1 { - space = true - } - l.writeToBuf(getColoredKey(k, lvl.String()), v, lvl, l.enableColor, space) - l.mu.Lock() - } else { - space := false - if count != len(l.fields)-1 { - space = true - } - l.writeToBuf(k, v, lvl, l.enableColor, space) + space := false + if count != len(l.fields)-1 { + space = true } + l.writeToBuf(k, v, lvl, l.enableColor, space) count++ } l.bufW.WriteString("\n")