mtlog/with_perf_test.go at main · willibrandon/mtlog · GitHub

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
package mtlog

import (
	"testing"

	"github.com/willibrandon/mtlog/core"
	"github.com/willibrandon/mtlog/sinks"
)

// BenchmarkWithPerformance validates that With() meets our performance targets
func BenchmarkWithPerformance(b *testing.B) {
	logger := New(
		WithSink(sinks.NewMemorySink()),
		WithMinimumLevel(core.InformationLevel),
	)

	b.Run("With_2Fields", func(b *testing.B) {
		b.ReportAllocs()
		b.ResetTimer()

		for i := 0; i < b.N; i++ {
			l := logger.With("key1", "value1", "key2", 42)
			_ = l
		}

		// Verify we achieve 2 allocations (logger + fields)
		allocsPerOp := testing.AllocsPerRun(100, func() {
			_ = logger.With("key1", "value1", "key2", 42)
		})

		if allocsPerOp > 2 {
			b.Errorf("Performance regression: expected 2 allocs, got %.2f allocs/op", allocsPerOp)
		}
	})

	b.Run("With_8Fields", func(b *testing.B) {
		b.ReportAllocs()
		b.ResetTimer()

		for i := 0; i < b.N; i++ {
			l := logger.With(
				"field1", "value1",
				"field2", 42,
				"field3", true,
				"field4", 3.14,
				"field5", "value5",
				"field6", 100,
				"field7", false,
				"field8", 2.71,
			)
			_ = l
		}

		// Still should be 2 allocations
		allocsPerOp := testing.AllocsPerRun(100, func() {
			_ = logger.With(
				"f1", 1, "f2", 2, "f3", 3, "f4", 4,
				"f5", 5, "f6", 6, "f7", 7, "f8", 8,
			)
		})

		if allocsPerOp > 2 {
			b.Errorf("Performance regression: expected 2 allocs, got %.2f allocs/op", allocsPerOp)
		}
	})

	b.Run("ChainedWith", func(b *testing.B) {
		base := logger.With("service", "api", "version", "1.0")

		b.ReportAllocs()
		b.ResetTimer()

		for i := 0; i < b.N; i++ {
			l := base.With("request_id", i, "user_id", i*2)
			_ = l
		}

		// Chained operations may need to merge fields
		allocsPerOp := testing.AllocsPerRun(100, func() {
			_ = base.With("request_id", 1, "user_id", 2)
		})

		if allocsPerOp > 3 {
			b.Errorf("Performance regression: expected <=3 allocs for chained With, got %.2f", allocsPerOp)
		}
	})
}

// BenchmarkWithRealWorld tests realistic usage patterns
func BenchmarkWithRealWorld(b *testing.B) {
	logger := New(
		WithSink(sinks.NewMemorySink()),
		WithMinimumLevel(core.InformationLevel),
	)

	b.Run("HTTPRequest", func(b *testing.B) {
		b.ReportAllocs()
		b.ResetTimer()

		for i := 0; i < b.N; i++ {
			logger.With(
				"method", "GET",
				"path", "/api/users",
				"status", 200,
				"duration_ms", 42,
				"user_id", 123,
				"trace_id", "abc-xyz",
			).Info("Request handled")
		}
	})

	b.Run("BaseLogger_Reuse", func(b *testing.B) {
		base := logger.With("service", "api", "env", "prod")

		b.ReportAllocs()
		b.ResetTimer()

		for i := 0; i < b.N; i++ {
			base.With("request_id", i).Info("Request {RequestId} handled", i)
		}
	})
}