Skip to content

Commit

Permalink
fix: Fix panic incase of concurrent colored loggging.
Browse files Browse the repository at this point in the history
Also changed benchmarks to run parallelly.
  • Loading branch information
iamd3vil committed Jun 27, 2022
1 parent e0cb9b1 commit 582b572
Show file tree
Hide file tree
Showing 2 changed files with 106 additions and 94 deletions.
181 changes: 102 additions & 79 deletions benchmark_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -13,19 +13,23 @@ 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) {
logger := logf.New()
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) {
Expand All @@ -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) {
Expand All @@ -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) {
Expand All @@ -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) {
Expand All @@ -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) {
Expand All @@ -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) {
Expand All @@ -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) {
Expand All @@ -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) {
Expand All @@ -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) {
Expand All @@ -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")
}
})
}
19 changes: 4 additions & 15 deletions log.go
Original file line number Diff line number Diff line change
Expand Up @@ -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")
Expand Down

0 comments on commit 582b572

Please sign in to comment.