1// Copyright (c) 2016 Uber Technologies, Inc. 2// 3// Permission is hereby granted, free of charge, to any person obtaining a copy 4// of this software and associated documentation files (the "Software"), to deal 5// in the Software without restriction, including without limitation the rights 6// to use, copy, modify, merge, publish, distribute, sublicense, and/or sell 7// copies of the Software, and to permit persons to whom the Software is 8// furnished to do so, subject to the following conditions: 9// 10// The above copyright notice and this permission notice shall be included in 11// all copies or substantial portions of the Software. 12// 13// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR 14// IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, 15// FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE 16// AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER 17// LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, 18// OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN 19// THE SOFTWARE. 20 21package zap 22 23import ( 24 "errors" 25 "testing" 26 "time" 27 28 "go.uber.org/zap/zapcore" 29 "go.uber.org/zap/zaptest" 30) 31 32type user struct { 33 Name string 34 Email string 35 CreatedAt time.Time 36} 37 38func (u *user) MarshalLogObject(enc zapcore.ObjectEncoder) error { 39 enc.AddString("name", u.Name) 40 enc.AddString("email", u.Email) 41 enc.AddInt64("created_at", u.CreatedAt.UnixNano()) 42 return nil 43} 44 45var _jane = &user{ 46 Name: "Jane Doe", 47 Email: "jane@test.com", 48 CreatedAt: time.Date(1980, 1, 1, 12, 0, 0, 0, time.UTC), 49} 50 51func withBenchedLogger(b *testing.B, f func(*Logger)) { 52 logger := New( 53 zapcore.NewCore( 54 zapcore.NewJSONEncoder(NewProductionConfig().EncoderConfig), 55 &zaptest.Discarder{}, 56 DebugLevel, 57 )) 58 b.ResetTimer() 59 b.RunParallel(func(pb *testing.PB) { 60 for pb.Next() { 61 f(logger) 62 } 63 }) 64} 65 66func BenchmarkNoContext(b *testing.B) { 67 withBenchedLogger(b, func(log *Logger) { 68 log.Info("No context.") 69 }) 70} 71 72func BenchmarkBoolField(b *testing.B) { 73 withBenchedLogger(b, func(log *Logger) { 74 log.Info("Boolean.", Bool("foo", true)) 75 }) 76} 77 78func BenchmarkByteStringField(b *testing.B) { 79 val := []byte("bar") 80 withBenchedLogger(b, func(log *Logger) { 81 log.Info("ByteString.", ByteString("foo", val)) 82 }) 83} 84 85func BenchmarkFloat64Field(b *testing.B) { 86 withBenchedLogger(b, func(log *Logger) { 87 log.Info("Floating point.", Float64("foo", 3.14)) 88 }) 89} 90 91func BenchmarkIntField(b *testing.B) { 92 withBenchedLogger(b, func(log *Logger) { 93 log.Info("Integer.", Int("foo", 42)) 94 }) 95} 96 97func BenchmarkInt64Field(b *testing.B) { 98 withBenchedLogger(b, func(log *Logger) { 99 log.Info("64-bit integer.", Int64("foo", 42)) 100 }) 101} 102 103func BenchmarkStringField(b *testing.B) { 104 withBenchedLogger(b, func(log *Logger) { 105 log.Info("Strings.", String("foo", "bar")) 106 }) 107} 108 109func BenchmarkStringerField(b *testing.B) { 110 withBenchedLogger(b, func(log *Logger) { 111 log.Info("Level.", Stringer("foo", InfoLevel)) 112 }) 113} 114 115func BenchmarkTimeField(b *testing.B) { 116 t := time.Unix(0, 0) 117 withBenchedLogger(b, func(log *Logger) { 118 log.Info("Time.", Time("foo", t)) 119 }) 120} 121 122func BenchmarkDurationField(b *testing.B) { 123 withBenchedLogger(b, func(log *Logger) { 124 log.Info("Duration", Duration("foo", time.Second)) 125 }) 126} 127 128func BenchmarkErrorField(b *testing.B) { 129 err := errors.New("egad") 130 withBenchedLogger(b, func(log *Logger) { 131 log.Info("Error.", Error(err)) 132 }) 133} 134 135func BenchmarkErrorsField(b *testing.B) { 136 errs := []error{ 137 errors.New("egad"), 138 errors.New("oh no"), 139 errors.New("dear me"), 140 errors.New("such fail"), 141 } 142 withBenchedLogger(b, func(log *Logger) { 143 log.Info("Errors.", Errors("errors", errs)) 144 }) 145} 146 147func BenchmarkStackField(b *testing.B) { 148 withBenchedLogger(b, func(log *Logger) { 149 log.Info("Error.", Stack("stacktrace")) 150 }) 151} 152 153func BenchmarkObjectField(b *testing.B) { 154 withBenchedLogger(b, func(log *Logger) { 155 log.Info("Arbitrary ObjectMarshaler.", Object("user", _jane)) 156 }) 157} 158 159func BenchmarkReflectField(b *testing.B) { 160 withBenchedLogger(b, func(log *Logger) { 161 log.Info("Reflection-based serialization.", Reflect("user", _jane)) 162 }) 163} 164 165func BenchmarkAddCallerHook(b *testing.B) { 166 logger := New( 167 zapcore.NewCore( 168 zapcore.NewJSONEncoder(NewProductionConfig().EncoderConfig), 169 &zaptest.Discarder{}, 170 InfoLevel, 171 ), 172 AddCaller(), 173 ) 174 b.ResetTimer() 175 b.RunParallel(func(pb *testing.PB) { 176 for pb.Next() { 177 logger.Info("Caller.") 178 } 179 }) 180} 181 182func Benchmark10Fields(b *testing.B) { 183 withBenchedLogger(b, func(log *Logger) { 184 log.Info("Ten fields, passed at the log site.", 185 Int("one", 1), 186 Int("two", 2), 187 Int("three", 3), 188 Int("four", 4), 189 Int("five", 5), 190 Int("six", 6), 191 Int("seven", 7), 192 Int("eight", 8), 193 Int("nine", 9), 194 Int("ten", 10), 195 ) 196 }) 197} 198 199func Benchmark100Fields(b *testing.B) { 200 const batchSize = 50 201 logger := New(zapcore.NewCore( 202 zapcore.NewJSONEncoder(NewProductionConfig().EncoderConfig), 203 &zaptest.Discarder{}, 204 DebugLevel, 205 )) 206 207 // Don't include allocating these helper slices in the benchmark. Since 208 // access to them isn't synchronized, we can't run the benchmark in 209 // parallel. 210 first := make([]zapcore.Field, batchSize) 211 second := make([]zapcore.Field, batchSize) 212 b.ResetTimer() 213 214 for i := 0; i < b.N; i++ { 215 for i := 0; i < batchSize; i++ { 216 // We're duplicating keys, but that doesn't affect performance. 217 first[i] = Int("foo", i) 218 second[i] = Int("foo", i+batchSize) 219 } 220 logger.With(first...).Info("Child loggers with lots of context.", second...) 221 } 222} 223