1
2
3
4
5
6
7 package logger
8
9 import (
10 "bytes"
11 "encoding/json"
12 "fmt"
13 "os"
14 "reflect"
15 "sync"
16 "testing"
17
18 "go.mongodb.org/mongo-driver/internal/assert"
19 )
20
21 type mockLogSink struct{}
22
23 func (mockLogSink) Info(int, string, ...interface{}) {}
24 func (mockLogSink) Error(error, string, ...interface{}) {}
25
26 func BenchmarkLogger(b *testing.B) {
27 b.ReportAllocs()
28 b.ResetTimer()
29
30 b.Run("Print", func(b *testing.B) {
31 b.ReportAllocs()
32 b.ResetTimer()
33
34 logger, err := New(mockLogSink{}, 0, map[Component]Level{
35 ComponentCommand: LevelDebug,
36 })
37
38 if err != nil {
39 b.Fatal(err)
40 }
41
42 b.RunParallel(func(pb *testing.PB) {
43 for pb.Next() {
44 logger.Print(LevelInfo, ComponentCommand, "foo", "bar", "baz")
45 }
46 })
47 })
48 }
49
50 func mockKeyValues(length int) (KeyValues, map[string]interface{}) {
51 keysAndValues := KeyValues{}
52 m := map[string]interface{}{}
53
54 for i := 0; i < length; i++ {
55 keyName := fmt.Sprintf("key%d", i)
56 valueName := fmt.Sprintf("value%d", i)
57
58 keysAndValues.Add(keyName, valueName)
59 m[keyName] = valueName
60 }
61
62 return keysAndValues, m
63 }
64
65 func BenchmarkIOSinkInfo(b *testing.B) {
66 keysAndValues, _ := mockKeyValues(10)
67
68 b.ReportAllocs()
69 b.ResetTimer()
70
71 sink := NewIOSink(bytes.NewBuffer(nil))
72
73 b.RunParallel(func(pb *testing.PB) {
74 for pb.Next() {
75 sink.Info(0, "foo", keysAndValues...)
76 }
77 })
78 }
79
80 func TestIOSinkInfo(t *testing.T) {
81 t.Parallel()
82
83 const threshold = 1000
84
85 mockKeyValues, kvmap := mockKeyValues(10)
86
87 buf := new(bytes.Buffer)
88 sink := NewIOSink(buf)
89
90 wg := sync.WaitGroup{}
91 wg.Add(threshold)
92
93 for i := 0; i < threshold; i++ {
94 go func() {
95 defer wg.Done()
96
97 sink.Info(0, "foo", mockKeyValues...)
98 }()
99 }
100
101 wg.Wait()
102
103 dec := json.NewDecoder(buf)
104 for dec.More() {
105 var m map[string]interface{}
106 if err := dec.Decode(&m); err != nil {
107 t.Fatalf("error unmarshaling JSON: %v", err)
108 }
109
110 delete(m, KeyTimestamp)
111 delete(m, KeyMessage)
112
113 if !reflect.DeepEqual(m, kvmap) {
114 t.Fatalf("expected %v, got %v", kvmap, m)
115 }
116 }
117 }
118
119 func TestSelectMaxDocumentLength(t *testing.T) {
120 for _, tcase := range []struct {
121 name string
122 arg uint
123 expected uint
124 env map[string]string
125 }{
126 {
127 name: "default",
128 arg: 0,
129 expected: DefaultMaxDocumentLength,
130 },
131 {
132 name: "non-zero",
133 arg: 100,
134 expected: 100,
135 },
136 {
137 name: "valid env",
138 arg: 0,
139 expected: 100,
140 env: map[string]string{
141 maxDocumentLengthEnvVar: "100",
142 },
143 },
144 {
145 name: "invalid env",
146 arg: 0,
147 expected: DefaultMaxDocumentLength,
148 env: map[string]string{
149 maxDocumentLengthEnvVar: "foo",
150 },
151 },
152 } {
153 tcase := tcase
154
155 t.Run(tcase.name, func(t *testing.T) {
156 for k, v := range tcase.env {
157 t.Setenv(k, v)
158 }
159
160 actual := selectMaxDocumentLength(tcase.arg)
161 if actual != tcase.expected {
162 t.Errorf("expected %d, got %d", tcase.expected, actual)
163 }
164 })
165 }
166 }
167
168 func TestSelectLogSink(t *testing.T) {
169 for _, tcase := range []struct {
170 name string
171 arg LogSink
172 expected LogSink
173 env map[string]string
174 }{
175 {
176 name: "default",
177 arg: nil,
178 expected: NewIOSink(os.Stderr),
179 },
180 {
181 name: "non-nil",
182 arg: mockLogSink{},
183 expected: mockLogSink{},
184 },
185 {
186 name: "stdout",
187 arg: nil,
188 expected: NewIOSink(os.Stdout),
189 env: map[string]string{
190 logSinkPathEnvVar: logSinkPathStdout,
191 },
192 },
193 {
194 name: "stderr",
195 arg: nil,
196 expected: NewIOSink(os.Stderr),
197 env: map[string]string{
198 logSinkPathEnvVar: logSinkPathStderr,
199 },
200 },
201 } {
202 tcase := tcase
203
204 t.Run(tcase.name, func(t *testing.T) {
205 for k, v := range tcase.env {
206 t.Setenv(k, v)
207 }
208
209 actual, _, _ := selectLogSink(tcase.arg)
210 if !reflect.DeepEqual(actual, tcase.expected) {
211 t.Errorf("expected %+v, got %+v", tcase.expected, actual)
212 }
213 })
214 }
215 }
216
217 func TestSelectedComponentLevels(t *testing.T) {
218 for _, tcase := range []struct {
219 name string
220 arg map[Component]Level
221 expected map[Component]Level
222 env map[string]string
223 }{
224 {
225 name: "default",
226 arg: nil,
227 expected: map[Component]Level{
228 ComponentCommand: LevelOff,
229 ComponentTopology: LevelOff,
230 ComponentServerSelection: LevelOff,
231 ComponentConnection: LevelOff,
232 },
233 },
234 {
235 name: "non-nil",
236 arg: map[Component]Level{
237 ComponentCommand: LevelDebug,
238 },
239 expected: map[Component]Level{
240 ComponentCommand: LevelDebug,
241 ComponentTopology: LevelOff,
242 ComponentServerSelection: LevelOff,
243 ComponentConnection: LevelOff,
244 },
245 },
246 {
247 name: "valid env",
248 arg: nil,
249 expected: map[Component]Level{
250 ComponentCommand: LevelDebug,
251 ComponentTopology: LevelInfo,
252 ComponentServerSelection: LevelOff,
253 ComponentConnection: LevelOff,
254 },
255 env: map[string]string{
256 mongoDBLogCommandEnvVar: levelLiteralDebug,
257 mongoDBLogTopologyEnvVar: levelLiteralInfo,
258 },
259 },
260 {
261 name: "invalid env",
262 arg: nil,
263 expected: map[Component]Level{
264 ComponentCommand: LevelOff,
265 ComponentTopology: LevelOff,
266 ComponentServerSelection: LevelOff,
267 ComponentConnection: LevelOff,
268 },
269 env: map[string]string{
270 mongoDBLogCommandEnvVar: "foo",
271 mongoDBLogTopologyEnvVar: "bar",
272 },
273 },
274 } {
275 tcase := tcase
276
277 t.Run(tcase.name, func(t *testing.T) {
278 for k, v := range tcase.env {
279 t.Setenv(k, v)
280 }
281
282 actual := selectComponentLevels(tcase.arg)
283 for k, v := range tcase.expected {
284 if actual[k] != v {
285 t.Errorf("expected %d, got %d", v, actual[k])
286 }
287 }
288 })
289 }
290 }
291
292 func TestTruncate(t *testing.T) {
293 t.Parallel()
294
295 for _, tcase := range []struct {
296 name string
297 arg string
298 width uint
299 expected string
300 }{
301 {
302 name: "empty",
303 arg: "",
304 width: 0,
305 expected: "",
306 },
307 {
308 name: "short",
309 arg: "foo",
310 width: DefaultMaxDocumentLength,
311 expected: "foo",
312 },
313 {
314 name: "long",
315 arg: "foo bar baz",
316 width: 9,
317 expected: "foo bar b...",
318 },
319 {
320 name: "multi-byte",
321 arg: "你好",
322 width: 4,
323 expected: "你...",
324 },
325 } {
326 tcase := tcase
327
328 t.Run(tcase.name, func(t *testing.T) {
329 t.Parallel()
330
331 actual := truncate(tcase.arg, tcase.width)
332 if actual != tcase.expected {
333 t.Errorf("expected %q, got %q", tcase.expected, actual)
334 }
335 })
336 }
337
338 }
339
340 func TestLogger_LevelComponentEnabled(t *testing.T) {
341 t.Parallel()
342
343 tests := []struct {
344 name string
345 logger Logger
346 level Level
347 component Component
348 want bool
349 }{
350 {
351 name: "zero",
352 logger: Logger{},
353 level: LevelOff,
354 component: ComponentCommand,
355 want: false,
356 },
357 {
358 name: "empty",
359 logger: Logger{
360 ComponentLevels: map[Component]Level{},
361 },
362 level: LevelOff,
363 component: ComponentCommand,
364 want: false,
365 },
366 {
367 name: "one level below",
368 logger: Logger{
369 ComponentLevels: map[Component]Level{
370 ComponentCommand: LevelDebug,
371 },
372 },
373 level: LevelInfo,
374 component: ComponentCommand,
375 want: true,
376 },
377 {
378 name: "equal levels",
379 logger: Logger{
380 ComponentLevels: map[Component]Level{
381 ComponentCommand: LevelDebug,
382 },
383 },
384 level: LevelDebug,
385 component: ComponentCommand,
386 want: true,
387 },
388 {
389 name: "one level above",
390 logger: Logger{
391 ComponentLevels: map[Component]Level{
392 ComponentCommand: LevelInfo,
393 },
394 },
395 level: LevelDebug,
396 component: ComponentCommand,
397 want: false,
398 },
399 {
400 name: "component mismatch",
401 logger: Logger{
402 ComponentLevels: map[Component]Level{
403 ComponentCommand: LevelDebug,
404 },
405 },
406 level: LevelDebug,
407 component: ComponentTopology,
408 want: false,
409 },
410 {
411 name: "component all enables with topology",
412 logger: Logger{
413 ComponentLevels: map[Component]Level{
414 ComponentAll: LevelDebug,
415 },
416 },
417 level: LevelDebug,
418 component: ComponentTopology,
419 want: true,
420 },
421 {
422 name: "component all enables with server selection",
423 logger: Logger{
424 ComponentLevels: map[Component]Level{
425 ComponentAll: LevelDebug,
426 },
427 },
428 level: LevelDebug,
429 component: ComponentServerSelection,
430 want: true,
431 },
432 {
433 name: "component all enables with connection",
434 logger: Logger{
435 ComponentLevels: map[Component]Level{
436 ComponentAll: LevelDebug,
437 },
438 },
439 level: LevelDebug,
440 component: ComponentConnection,
441 want: true,
442 },
443 {
444 name: "component all enables with command",
445 logger: Logger{
446 ComponentLevels: map[Component]Level{
447 ComponentAll: LevelDebug,
448 },
449 },
450 level: LevelDebug,
451 component: ComponentCommand,
452 want: true,
453 },
454 {
455 name: "component all enables with all",
456 logger: Logger{
457 ComponentLevels: map[Component]Level{
458 ComponentAll: LevelDebug,
459 },
460 },
461 level: LevelDebug,
462 component: ComponentAll,
463 want: true,
464 },
465 {
466 name: "component all does not enable with lower level",
467 logger: Logger{
468 ComponentLevels: map[Component]Level{
469 ComponentAll: LevelInfo,
470 },
471 },
472 level: LevelDebug,
473 component: ComponentCommand,
474 want: false,
475 },
476 {
477 name: "component all has a lower log level than command",
478 logger: Logger{
479 ComponentLevels: map[Component]Level{
480 ComponentAll: LevelInfo,
481 ComponentCommand: LevelDebug,
482 },
483 },
484 level: LevelDebug,
485 component: ComponentCommand,
486 want: true,
487 },
488 {
489 name: "component all has a higher log level than command",
490 logger: Logger{
491 ComponentLevels: map[Component]Level{
492 ComponentAll: LevelDebug,
493 ComponentCommand: LevelInfo,
494 },
495 },
496 level: LevelDebug,
497 component: ComponentCommand,
498 want: true,
499 },
500 }
501
502 for _, tcase := range tests {
503 tcase := tcase
504
505 t.Run(tcase.name, func(t *testing.T) {
506 t.Parallel()
507
508 got := tcase.logger.LevelComponentEnabled(tcase.level, tcase.component)
509 assert.Equal(t, tcase.want, got, "unexpected result for LevelComponentEnabled")
510 })
511 }
512 }
513
View as plain text