1package zerolog
2
3import (
4	"errors"
5	"io/ioutil"
6	"net"
7	"testing"
8	"time"
9)
10
11var (
12	errExample  = errors.New("fail")
13	fakeMessage = "Test logging, but use a somewhat realistic message length."
14)
15
16func BenchmarkLogEmpty(b *testing.B) {
17	logger := New(ioutil.Discard)
18	b.ResetTimer()
19	b.RunParallel(func(pb *testing.PB) {
20		for pb.Next() {
21			logger.Log().Msg("")
22		}
23	})
24}
25
26func BenchmarkDisabled(b *testing.B) {
27	logger := New(ioutil.Discard).Level(Disabled)
28	b.ResetTimer()
29	b.RunParallel(func(pb *testing.PB) {
30		for pb.Next() {
31			logger.Info().Msg(fakeMessage)
32		}
33	})
34}
35
36func BenchmarkInfo(b *testing.B) {
37	logger := New(ioutil.Discard)
38	b.ResetTimer()
39	b.RunParallel(func(pb *testing.PB) {
40		for pb.Next() {
41			logger.Info().Msg(fakeMessage)
42		}
43	})
44}
45
46func BenchmarkContextFields(b *testing.B) {
47	logger := New(ioutil.Discard).With().
48		Str("string", "four!").
49		Time("time", time.Time{}).
50		Int("int", 123).
51		Float32("float", -2.203230293249593).
52		Logger()
53	b.ResetTimer()
54	b.RunParallel(func(pb *testing.PB) {
55		for pb.Next() {
56			logger.Info().Msg(fakeMessage)
57		}
58	})
59}
60
61func BenchmarkContextAppend(b *testing.B) {
62	logger := New(ioutil.Discard).With().
63		Str("foo", "bar").
64		Logger()
65	b.ResetTimer()
66	b.RunParallel(func(pb *testing.PB) {
67		for pb.Next() {
68			logger.With().Str("bar", "baz")
69		}
70	})
71}
72
73func BenchmarkLogFields(b *testing.B) {
74	logger := New(ioutil.Discard)
75	b.ResetTimer()
76	b.RunParallel(func(pb *testing.PB) {
77		for pb.Next() {
78			logger.Info().
79				Str("string", "four!").
80				Time("time", time.Time{}).
81				Int("int", 123).
82				Float32("float", -2.203230293249593).
83				Msg(fakeMessage)
84		}
85	})
86}
87
88type obj struct {
89	Pub  string
90	Tag  string `json:"tag"`
91	priv int
92}
93
94func (o obj) MarshalZerologObject(e *Event) {
95	e.Str("Pub", o.Pub).
96		Str("Tag", o.Tag).
97		Int("priv", o.priv)
98}
99
100func BenchmarkLogArrayObject(b *testing.B) {
101	obj1 := obj{"a", "b", 2}
102	obj2 := obj{"c", "d", 3}
103	obj3 := obj{"e", "f", 4}
104	logger := New(ioutil.Discard)
105	b.ResetTimer()
106	b.ReportAllocs()
107	for i := 0; i < b.N; i++ {
108		arr := Arr()
109		arr.Object(&obj1)
110		arr.Object(&obj2)
111		arr.Object(&obj3)
112		logger.Info().Array("objects", arr).Msg("test")
113	}
114}
115
116func BenchmarkLogFieldType(b *testing.B) {
117	bools := []bool{true, false, true, false, true, false, true, false, true, false}
118	ints := []int{0, 1, 2, 3, 4, 5, 6, 7, 8, 9}
119	floats := []float64{0, 1, 2, 3, 4, 5, 6, 7, 8, 9}
120	strings := []string{"a", "b", "c", "d", "e", "f", "g", "h", "i", "j"}
121	durations := []time.Duration{0, 1, 2, 3, 4, 5, 6, 7, 8, 9}
122	times := []time.Time{
123		time.Unix(0, 0),
124		time.Unix(1, 0),
125		time.Unix(2, 0),
126		time.Unix(3, 0),
127		time.Unix(4, 0),
128		time.Unix(5, 0),
129		time.Unix(6, 0),
130		time.Unix(7, 0),
131		time.Unix(8, 0),
132		time.Unix(9, 0),
133	}
134	interfaces := []struct {
135		Pub  string
136		Tag  string `json:"tag"`
137		priv int
138	}{
139		{"a", "a", 0},
140		{"a", "a", 0},
141		{"a", "a", 0},
142		{"a", "a", 0},
143		{"a", "a", 0},
144		{"a", "a", 0},
145		{"a", "a", 0},
146		{"a", "a", 0},
147		{"a", "a", 0},
148		{"a", "a", 0},
149	}
150	objects := []obj{
151		obj{"a", "a", 0},
152		obj{"a", "a", 0},
153		obj{"a", "a", 0},
154		obj{"a", "a", 0},
155		obj{"a", "a", 0},
156		obj{"a", "a", 0},
157		obj{"a", "a", 0},
158		obj{"a", "a", 0},
159		obj{"a", "a", 0},
160		obj{"a", "a", 0},
161	}
162	errs := []error{errors.New("a"), errors.New("b"), errors.New("c"), errors.New("d"), errors.New("e")}
163	types := map[string]func(e *Event) *Event{
164		"Bool": func(e *Event) *Event {
165			return e.Bool("k", bools[0])
166		},
167		"Bools": func(e *Event) *Event {
168			return e.Bools("k", bools)
169		},
170		"Int": func(e *Event) *Event {
171			return e.Int("k", ints[0])
172		},
173		"Ints": func(e *Event) *Event {
174			return e.Ints("k", ints)
175		},
176		"Float": func(e *Event) *Event {
177			return e.Float64("k", floats[0])
178		},
179		"Floats": func(e *Event) *Event {
180			return e.Floats64("k", floats)
181		},
182		"Str": func(e *Event) *Event {
183			return e.Str("k", strings[0])
184		},
185		"Strs": func(e *Event) *Event {
186			return e.Strs("k", strings)
187		},
188		"Err": func(e *Event) *Event {
189			return e.Err(errs[0])
190		},
191		"Errs": func(e *Event) *Event {
192			return e.Errs("k", errs)
193		},
194		"Time": func(e *Event) *Event {
195			return e.Time("k", times[0])
196		},
197		"Times": func(e *Event) *Event {
198			return e.Times("k", times)
199		},
200		"Dur": func(e *Event) *Event {
201			return e.Dur("k", durations[0])
202		},
203		"Durs": func(e *Event) *Event {
204			return e.Durs("k", durations)
205		},
206		"Interface": func(e *Event) *Event {
207			return e.Interface("k", interfaces[0])
208		},
209		"Interfaces": func(e *Event) *Event {
210			return e.Interface("k", interfaces)
211		},
212		"Interface(Object)": func(e *Event) *Event {
213			return e.Interface("k", objects[0])
214		},
215		"Interface(Objects)": func(e *Event) *Event {
216			return e.Interface("k", objects)
217		},
218		"Object": func(e *Event) *Event {
219			return e.Object("k", objects[0])
220		},
221	}
222	logger := New(ioutil.Discard)
223	b.ResetTimer()
224	for name := range types {
225		f := types[name]
226		b.Run(name, func(b *testing.B) {
227			b.RunParallel(func(pb *testing.PB) {
228				for pb.Next() {
229					f(logger.Info()).Msg("")
230				}
231			})
232		})
233	}
234}
235
236func BenchmarkContextFieldType(b *testing.B) {
237	oldFormat := TimeFieldFormat
238	TimeFieldFormat = TimeFormatUnix
239	defer func() { TimeFieldFormat = oldFormat }()
240	bools := []bool{true, false, true, false, true, false, true, false, true, false}
241	ints := []int{0, 1, 2, 3, 4, 5, 6, 7, 8, 9}
242	floats := []float64{0, 1, 2, 3, 4, 5, 6, 7, 8, 9}
243	strings := []string{"a", "b", "c", "d", "e", "f", "g", "h", "i", "j"}
244	stringer := net.IP{127, 0, 0, 1}
245	durations := []time.Duration{0, 1, 2, 3, 4, 5, 6, 7, 8, 9}
246	times := []time.Time{
247		time.Unix(0, 0),
248		time.Unix(1, 0),
249		time.Unix(2, 0),
250		time.Unix(3, 0),
251		time.Unix(4, 0),
252		time.Unix(5, 0),
253		time.Unix(6, 0),
254		time.Unix(7, 0),
255		time.Unix(8, 0),
256		time.Unix(9, 0),
257	}
258	interfaces := []struct {
259		Pub  string
260		Tag  string `json:"tag"`
261		priv int
262	}{
263		{"a", "a", 0},
264		{"a", "a", 0},
265		{"a", "a", 0},
266		{"a", "a", 0},
267		{"a", "a", 0},
268		{"a", "a", 0},
269		{"a", "a", 0},
270		{"a", "a", 0},
271		{"a", "a", 0},
272		{"a", "a", 0},
273	}
274	objects := []obj{
275		obj{"a", "a", 0},
276		obj{"a", "a", 0},
277		obj{"a", "a", 0},
278		obj{"a", "a", 0},
279		obj{"a", "a", 0},
280		obj{"a", "a", 0},
281		obj{"a", "a", 0},
282		obj{"a", "a", 0},
283		obj{"a", "a", 0},
284		obj{"a", "a", 0},
285	}
286	errs := []error{errors.New("a"), errors.New("b"), errors.New("c"), errors.New("d"), errors.New("e")}
287	types := map[string]func(c Context) Context{
288		"Bool": func(c Context) Context {
289			return c.Bool("k", bools[0])
290		},
291		"Bools": func(c Context) Context {
292			return c.Bools("k", bools)
293		},
294		"Int": func(c Context) Context {
295			return c.Int("k", ints[0])
296		},
297		"Ints": func(c Context) Context {
298			return c.Ints("k", ints)
299		},
300		"Float": func(c Context) Context {
301			return c.Float64("k", floats[0])
302		},
303		"Floats": func(c Context) Context {
304			return c.Floats64("k", floats)
305		},
306		"Str": func(c Context) Context {
307			return c.Str("k", strings[0])
308		},
309		"Strs": func(c Context) Context {
310			return c.Strs("k", strings)
311		},
312		"Stringer": func(c Context) Context {
313			return c.Stringer("k", stringer)
314		},
315		"Err": func(c Context) Context {
316			return c.Err(errs[0])
317		},
318		"Errs": func(c Context) Context {
319			return c.Errs("k", errs)
320		},
321		"Time": func(c Context) Context {
322			return c.Time("k", times[0])
323		},
324		"Times": func(c Context) Context {
325			return c.Times("k", times)
326		},
327		"Dur": func(c Context) Context {
328			return c.Dur("k", durations[0])
329		},
330		"Durs": func(c Context) Context {
331			return c.Durs("k", durations)
332		},
333		"Interface": func(c Context) Context {
334			return c.Interface("k", interfaces[0])
335		},
336		"Interfaces": func(c Context) Context {
337			return c.Interface("k", interfaces)
338		},
339		"Interface(Object)": func(c Context) Context {
340			return c.Interface("k", objects[0])
341		},
342		"Interface(Objects)": func(c Context) Context {
343			return c.Interface("k", objects)
344		},
345		"Object": func(c Context) Context {
346			return c.Object("k", objects[0])
347		},
348		"Timestamp": func(c Context) Context {
349			return c.Timestamp()
350		},
351	}
352	logger := New(ioutil.Discard)
353	b.ResetTimer()
354	for name := range types {
355		f := types[name]
356		b.Run(name, func(b *testing.B) {
357			b.RunParallel(func(pb *testing.PB) {
358				for pb.Next() {
359					l := f(logger.With()).Logger()
360					l.Info().Msg("")
361				}
362			})
363		})
364	}
365}
366