zap.Any add benchmarks

logger_bench_test.go

@@ -22,6 +22,8 @@ package zap
 
 import (
 	"errors"
+	"runtime"
+	"sync"
 	"testing"
 	"time"
 
@@ -238,3 +240,132 @@ func Benchmark100Fields(b *testing.B) {
 		logger.With(first...).Info("Child loggers with lots of context.", second...)
 	}
 }
+
+func dummy(wg *sync.WaitGroup, s string, i int) string {
+	if i == 0 {
+		wg.Wait()
+		return "1" + s
+	}
+	return dummy(wg, s, i-1)
+}
+
+// increaseAvgStack starts a background goroutine with a variable
+// stack size. The goal is to move the average stack size higher,
+// since https://go-review.googlesource.com/c/go/+/345889 this affects
+// goroutine starting stack size.
+func increaseAvgStack(n int) *sync.WaitGroup {
+	wg := sync.WaitGroup{}
+	wg.Add(1)
+
+	go dummy(&wg, "hi", n)
+	return &wg
+}
+
+func BenchmarkAny(b *testing.B) {
+	key := "some-long-string-longer-than-16"
+
+	tests := []struct {
+		name   string
+		typed  func() Field
+		anyArg any
+	}{
+		{
+			name:   "string",
+			typed:  func() Field { return String(key, "yet-another-long-string") },
+			anyArg: "yet-another-long-string",
+		},
+		{
+			name:   "stringer",
+			typed:  func() Field { return Stringer(key, InfoLevel) },
+			anyArg: InfoLevel,
+		},
+	}
+
+	for _, tt := range tests {
+		b.Run(tt.name, func(b *testing.B) {
+			b.Run("field-only", func(b *testing.B) {
+				b.Run("typed", func(b *testing.B) {
+					withBenchedLogger(b, func(log *Logger) {
+						f := tt.typed()
+						runtime.KeepAlive(f)
+					})
+				})
+				b.Run("any", func(b *testing.B) {
+					withBenchedLogger(b, func(log *Logger) {
+						f := Any(key, tt.anyArg)
+						runtime.KeepAlive(f)
+					})
+				})
+			})
+			b.Run("log", func(b *testing.B) {
+				b.Run("typed", func(b *testing.B) {
+					withBenchedLogger(b, func(log *Logger) {
+						log.Info("", tt.typed())
+					})
+				})
+				b.Run("any", func(b *testing.B) {
+					withBenchedLogger(b, func(log *Logger) {
+						log.Info("", Any(key, tt.anyArg))
+					})
+				})
+			})
+			b.Run("log-go", func(b *testing.B) {
+				b.Run("typed", func(b *testing.B) {
+					withBenchedLogger(b, func(log *Logger) {
+						var wg sync.WaitGroup
+						wg.Add(1)
+						go func() {
+							log.Info("", tt.typed())
+							wg.Done()
+						}()
+						wg.Wait()
+					})
+				})
+				b.Run("any", func(b *testing.B) {
+					withBenchedLogger(b, func(log *Logger) {
+						var wg sync.WaitGroup
+						wg.Add(1)
+						go func() {
+							log.Info("", Any(key, tt.anyArg))
+							wg.Done()
+						}()
+						wg.Wait()
+					})
+				})
+			})
+			// The stack growing below simulates production setup where some other
+			// goroutines exist and affect the starting goroutine stack size up.
+			// Otherwise, for tests with 2+ goroutines, the cost of starting the goroutine
+			// dominates and the cost of `any` stack overallocation is not visible.
+			b.Run("log-go-stack", func(b *testing.B) {
+				defer increaseAvgStack(1000).Done()
+				b.ResetTimer()
+				b.Run("typed", func(b *testing.B) {
+					withBenchedLogger(b, func(log *Logger) {
+						var wg sync.WaitGroup
+						wg.Add(1)
+						go func() {
+							log.Info("", tt.typed())
+							wg.Done()
+						}()
+						wg.Wait()
+					})
+				})
+				b.Run("any", func(b *testing.B) {
+					wg := sync.WaitGroup{}
+					wg.Add(b.N)
+					withBenchedLogger(b, func(log *Logger) {
+						var wg sync.WaitGroup
+						wg.Add(1)
+						go func() {
+							log.Info("", Any(key, tt.anyArg))
+							wg.Done()
+						}()
+						wg.Wait()
+					})
+				})
+				b.StopTimer()
+			})
+		})
+	}
+}