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