-
Notifications
You must be signed in to change notification settings - Fork 3.6k
/
bench_test.go
141 lines (124 loc) · 3.33 KB
/
bench_test.go
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
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
package log_test
import (
"bytes"
"errors"
"io"
"testing"
"time"
"cosmossdk.io/log"
"github.com/rs/zerolog"
)
const message = "test message"
func BenchmarkLoggers(b *testing.B) {
b.ReportAllocs()
type benchCase struct {
name string
keyVals []any
}
// Just test two simple cases for the nop logger benchmarks.
nopCases := []benchCase{
{name: "empty key vals"},
{name: "single string", keyVals: []any{"foo", "bar"}},
}
benchCases := append(nopCases, []benchCase{
{
name: "single small int",
keyVals: []any{"foo", 1},
},
{
// Small numbers may be optimized, so check if an unusual/larger number performs different.
name: "single largeish int",
keyVals: []any{"foo", 123456789},
},
{
name: "single float",
keyVals: []any{"foo", 2.71828182},
},
{
name: "single byte slice",
keyVals: []any{"foo", []byte{0xde, 0xad, 0xbe, 0xef}},
},
{
name: "single duration",
keyVals: []any{"foo", 10 * time.Second},
},
{
name: "two values",
keyVals: []any{"foo", "foo", "bar", "bar"},
},
{
name: "four values",
keyVals: []any{"foo", "foo", "bar", "bar", "baz", "baz", "quux", "quux"},
},
{
name: "eight values",
keyVals: []any{"one", 1, "two", 2, "three", 3, "four", 4, "five", 5, "six", 6, "seven", 7, "eight", 8},
},
}...)
// If running with "go test -v", print out the log messages as a sanity check.
if testing.Verbose() {
checkBuf := new(bytes.Buffer)
for _, bc := range benchCases {
checkBuf.Reset()
zl := zerolog.New(checkBuf)
logger := log.NewCustomLogger(zl)
logger.Info(message, bc.keyVals...)
b.Logf("zero logger output for %s: %s", bc.name, checkBuf.String())
}
}
// The real logger exposed by this package,
// writing to an io.Discard writer,
// so that real write time is negligible.
b.Run("zerolog", func(b *testing.B) {
for _, bc := range benchCases {
bc := bc
b.Run(bc.name, func(b *testing.B) {
zl := zerolog.New(io.Discard)
logger := log.NewCustomLogger(zl)
for i := 0; i < b.N; i++ {
logger.Info(message, bc.keyVals...)
}
})
}
})
// The nop logger we use in tests,
// also useful as a reference for how expensive zerolog is.
b.Run("nop logger", func(b *testing.B) {
for _, bc := range nopCases {
bc := bc
b.Run(bc.name, func(b *testing.B) {
logger := log.NewNopLogger()
for i := 0; i < b.N; i++ {
logger.Info(message, bc.keyVals...)
}
})
}
})
}
func BenchmarkLoggers_StructuredVsFields(b *testing.B) {
b.ReportAllocs()
b.Run("logger structured", func(b *testing.B) {
zl := zerolog.New(io.Discard)
var logger log.Logger = log.NewCustomLogger(zl)
zerolog := logger.Impl().(*zerolog.Logger)
for i := 0; i < b.N; i++ {
zerolog.Info().Int64("foo", 100000).Msg(message)
zerolog.Info().Str("foo", "foo").Msg(message)
zerolog.Error().
Int64("foo", 100000).
Str("bar", "foo").
Bytes("other", []byte{0xde, 0xad, 0xbe, 0xef}).
Err(errors.New("error")).
Msg(message)
}
})
b.Run("logger", func(b *testing.B) {
zl := zerolog.New(io.Discard)
var logger log.Logger = log.NewCustomLogger(zl)
for i := 0; i < b.N; i++ {
logger.Info(message, "foo", 100000)
logger.Info(message, "foo", "foo")
logger.Error(message, "foo", 100000, "bar", "foo", "other", []byte{0xde, 0xad, 0xbe, 0xef}, "error", errors.New("error"))
}
})
}