1
16
17 package zap
18
19 import (
20 "bytes"
21 "encoding/json"
22 "flag"
23 "os"
24 "reflect"
25
26 "github.com/go-logr/logr"
27 . "github.com/onsi/ginkgo/v2"
28 . "github.com/onsi/gomega"
29 "go.uber.org/zap/zapcore"
30 corev1 "k8s.io/api/core/v1"
31 "k8s.io/apimachinery/pkg/apis/meta/v1/unstructured"
32 "k8s.io/apimachinery/pkg/types"
33 )
34
35
36 type testStringer struct{}
37
38 func (testStringer) String() string {
39 return "value"
40 }
41
42
43 type fakeSyncWriter bool
44
45 func (w *fakeSyncWriter) Write(p []byte) (int, error) {
46 return len(p), nil
47 }
48
49 func (w *fakeSyncWriter) Sync() error {
50 *w = true
51 return nil
52 }
53
54
55 type logInfo struct {
56 name []string
57 tags []interface{}
58 msg string
59 }
60
61
62 type fakeLoggerRoot struct {
63 messages []logInfo
64 }
65
66 var _ logr.LogSink = &fakeLogger{}
67
68
69
70
71 type fakeLogger struct {
72 name []string
73 tags []interface{}
74
75 root *fakeLoggerRoot
76 }
77
78 func (f *fakeLogger) Init(info logr.RuntimeInfo) {
79 }
80
81 func (f *fakeLogger) WithName(name string) logr.LogSink {
82 names := append([]string(nil), f.name...)
83 names = append(names, name)
84 return &fakeLogger{
85 name: names,
86 tags: f.tags,
87 root: f.root,
88 }
89 }
90
91 func (f *fakeLogger) WithValues(vals ...interface{}) logr.LogSink {
92 tags := append([]interface{}(nil), f.tags...)
93 tags = append(tags, vals...)
94 return &fakeLogger{
95 name: f.name,
96 tags: tags,
97 root: f.root,
98 }
99 }
100
101 func (f *fakeLogger) Error(err error, msg string, vals ...interface{}) {
102 tags := append([]interface{}(nil), f.tags...)
103 tags = append(tags, "error", err)
104 tags = append(tags, vals...)
105 f.root.messages = append(f.root.messages, logInfo{
106 name: append([]string(nil), f.name...),
107 tags: tags,
108 msg: msg,
109 })
110 }
111
112 func (f *fakeLogger) Info(level int, msg string, vals ...interface{}) {
113 tags := append([]interface{}(nil), f.tags...)
114 tags = append(tags, vals...)
115 f.root.messages = append(f.root.messages, logInfo{
116 name: append([]string(nil), f.name...),
117 tags: tags,
118 msg: msg,
119 })
120 }
121
122 func (f *fakeLogger) Enabled(level int) bool { return true }
123 func (f *fakeLogger) V(lvl int) logr.LogSink { return f }
124
125 var _ = Describe("Zap options setup", func() {
126 var opts *Options
127
128 BeforeEach(func() {
129 opts = &Options{}
130 })
131
132 It("should enable development mode", func() {
133 UseDevMode(true)(opts)
134 Expect(opts.Development).To(BeTrue())
135 })
136
137 It("should disable development mode", func() {
138 UseDevMode(false)(opts)
139 Expect(opts.Development).To(BeFalse())
140 })
141
142 It("should set a custom writer", func() {
143 var w fakeSyncWriter
144 WriteTo(&w)(opts)
145 Expect(opts.DestWriter).To(Equal(&w))
146 })
147 })
148
149 var _ = Describe("Zap logger setup", func() {
150 Context("when logging kubernetes objects", func() {
151 var logOut *bytes.Buffer
152 var logger logr.Logger
153
154 defineTests := func() {
155 It("should log a standard namespaced Kubernetes object name and namespace", func() {
156 pod := &corev1.Pod{}
157 pod.Name = "some-pod"
158 pod.Namespace = "some-ns"
159 logger.Info("here's a kubernetes object", "thing", pod)
160
161 outRaw := logOut.Bytes()
162 res := map[string]interface{}{}
163 Expect(json.Unmarshal(outRaw, &res)).To(Succeed())
164
165 Expect(res).To(HaveKeyWithValue("thing", map[string]interface{}{
166 "name": pod.Name,
167 "namespace": pod.Namespace,
168 }))
169 })
170
171 It("should work fine with normal stringers", func() {
172 logger.Info("here's a non-kubernetes stringer", "thing", testStringer{})
173 outRaw := logOut.Bytes()
174 res := map[string]interface{}{}
175 Expect(json.Unmarshal(outRaw, &res)).To(Succeed())
176
177 Expect(res).To(HaveKeyWithValue("thing", "value"))
178 })
179
180 It("should log a standard non-namespaced Kubernetes object name", func() {
181 node := &corev1.Node{}
182 node.Name = "some-node"
183 logger.Info("here's a kubernetes object", "thing", node)
184
185 outRaw := logOut.Bytes()
186 res := map[string]interface{}{}
187 Expect(json.Unmarshal(outRaw, &res)).To(Succeed())
188
189 Expect(res).To(HaveKeyWithValue("thing", map[string]interface{}{
190 "name": node.Name,
191 }))
192 })
193
194 It("should log a standard Kubernetes object's kind, if set", func() {
195 node := &corev1.Node{}
196 node.Name = "some-node"
197 node.APIVersion = "v1"
198 node.Kind = "Node"
199 logger.Info("here's a kubernetes object", "thing", node)
200
201 outRaw := logOut.Bytes()
202 res := map[string]interface{}{}
203 Expect(json.Unmarshal(outRaw, &res)).To(Succeed())
204
205 Expect(res).To(HaveKeyWithValue("thing", map[string]interface{}{
206 "name": node.Name,
207 "apiVersion": "v1",
208 "kind": "Node",
209 }))
210 })
211
212 It("should log a standard non-namespaced NamespacedName name", func() {
213 name := types.NamespacedName{Name: "some-node"}
214 logger.Info("here's a kubernetes object", "thing", name)
215
216 outRaw := logOut.Bytes()
217 res := map[string]interface{}{}
218 Expect(json.Unmarshal(outRaw, &res)).To(Succeed())
219
220 Expect(res).To(HaveKeyWithValue("thing", map[string]interface{}{
221 "name": name.Name,
222 }))
223 })
224
225 It("should log an unstructured Kubernetes object", func() {
226 pod := &unstructured.Unstructured{
227 Object: map[string]interface{}{
228 "metadata": map[string]interface{}{
229 "name": "some-pod",
230 "namespace": "some-ns",
231 },
232 },
233 }
234 logger.Info("here's a kubernetes object", "thing", pod)
235
236 outRaw := logOut.Bytes()
237 res := map[string]interface{}{}
238 Expect(json.Unmarshal(outRaw, &res)).To(Succeed())
239
240 Expect(res).To(HaveKeyWithValue("thing", map[string]interface{}{
241 "name": "some-pod",
242 "namespace": "some-ns",
243 }))
244 })
245
246 It("should log a standard namespaced NamespacedName name and namespace", func() {
247 name := types.NamespacedName{Name: "some-pod", Namespace: "some-ns"}
248 logger.Info("here's a kubernetes object", "thing", name)
249
250 outRaw := logOut.Bytes()
251 res := map[string]interface{}{}
252 Expect(json.Unmarshal(outRaw, &res)).To(Succeed())
253
254 Expect(res).To(HaveKeyWithValue("thing", map[string]interface{}{
255 "name": name.Name,
256 "namespace": name.Namespace,
257 }))
258 })
259
260 It("should not panic with nil obj", func() {
261 var pod *corev1.Pod
262 logger.Info("here's a kubernetes object", "thing", pod)
263
264 outRaw := logOut.Bytes()
265 Expect(string(outRaw)).Should(ContainSubstring("got nil for runtime.Object"))
266 })
267 }
268
269 Context("with logger created using New", func() {
270 BeforeEach(func() {
271 logOut = new(bytes.Buffer)
272 By("setting up the logger")
273
274 logger = New(WriteTo(logOut), UseDevMode(false))
275 })
276 defineTests()
277 })
278 })
279 })
280
281 var _ = Describe("Zap log level flag options setup", func() {
282 var (
283 fromFlags Options
284 fs flag.FlagSet
285 logInfoLevel0 = "info text"
286 logDebugLevel1 = "debug 1 text"
287 logDebugLevel2 = "debug 2 text"
288 logDebugLevel3 = "debug 3 text"
289 )
290
291 BeforeEach(func() {
292 fromFlags = Options{}
293 fs = *flag.NewFlagSet(os.Args[0], flag.ExitOnError)
294 })
295
296 Context("with zap-log-level options provided", func() {
297 It("Should output logs for info and debug zap-log-level.", func() {
298 args := []string{"--zap-log-level=debug"}
299 fromFlags.BindFlags(&fs)
300 err := fs.Parse(args)
301 Expect(err).ToNot(HaveOccurred())
302 logOut := new(bytes.Buffer)
303
304 logger := New(UseFlagOptions(&fromFlags), WriteTo(logOut))
305 logger.V(0).Info(logInfoLevel0)
306 logger.V(1).Info(logDebugLevel1)
307
308 outRaw := logOut.Bytes()
309
310 Expect(string(outRaw)).Should(ContainSubstring(logInfoLevel0))
311 Expect(string(outRaw)).Should(ContainSubstring(logDebugLevel1))
312 })
313
314 It("Should output only error logs, otherwise empty logs", func() {
315 args := []string{"--zap-log-level=error"}
316 fromFlags.BindFlags(&fs)
317 err := fs.Parse(args)
318 Expect(err).ToNot(HaveOccurred())
319
320 logOut := new(bytes.Buffer)
321
322 logger := New(UseFlagOptions(&fromFlags), WriteTo(logOut))
323 logger.V(0).Info(logInfoLevel0)
324 logger.V(1).Info(logDebugLevel1)
325
326 outRaw := logOut.Bytes()
327
328 Expect(outRaw).To(BeEmpty())
329 })
330 })
331
332 Context("with zap-log-level with increased verbosity.", func() {
333 It("Should output debug and info log, with default production mode.", func() {
334 args := []string{"--zap-log-level=1"}
335 fromFlags.BindFlags(&fs)
336 err := fs.Parse(args)
337 Expect(err).ToNot(HaveOccurred())
338 logOut := new(bytes.Buffer)
339
340 logger := New(UseFlagOptions(&fromFlags), WriteTo(logOut))
341 logger.V(0).Info(logInfoLevel0)
342 logger.V(1).Info(logDebugLevel1)
343
344 outRaw := logOut.Bytes()
345
346 Expect(string(outRaw)).Should(ContainSubstring(logInfoLevel0))
347 Expect(string(outRaw)).Should(ContainSubstring(logDebugLevel1))
348 })
349
350 It("Should output info and debug logs, with development mode.", func() {
351 args := []string{"--zap-log-level=1", "--zap-devel=true"}
352 fromFlags.BindFlags(&fs)
353 err := fs.Parse(args)
354 Expect(err).ToNot(HaveOccurred())
355 logOut := new(bytes.Buffer)
356
357 logger := New(UseFlagOptions(&fromFlags), WriteTo(logOut))
358 logger.V(0).Info(logInfoLevel0)
359 logger.V(1).Info(logDebugLevel1)
360
361 outRaw := logOut.Bytes()
362
363 Expect(string(outRaw)).Should(ContainSubstring(logInfoLevel0))
364 Expect(string(outRaw)).Should(ContainSubstring(logDebugLevel1))
365 })
366
367 It("Should output info, and debug logs with increased verbosity, and with development mode set to true.", func() {
368 args := []string{"--zap-log-level=3", "--zap-devel=false"}
369 fromFlags.BindFlags(&fs)
370 err := fs.Parse(args)
371 Expect(err).ToNot(HaveOccurred())
372 logOut := new(bytes.Buffer)
373
374 logger := New(UseFlagOptions(&fromFlags), WriteTo(logOut))
375 logger.V(0).Info(logInfoLevel0)
376 logger.V(1).Info(logDebugLevel1)
377 logger.V(2).Info(logDebugLevel2)
378 logger.V(3).Info(logDebugLevel3)
379
380 outRaw := logOut.Bytes()
381
382 Expect(string(outRaw)).Should(ContainSubstring(logInfoLevel0))
383 Expect(string(outRaw)).Should(ContainSubstring(logDebugLevel1))
384 Expect(string(outRaw)).Should(ContainSubstring(logDebugLevel2))
385 Expect(string(outRaw)).Should(ContainSubstring(logDebugLevel3))
386 })
387 It("Should output info, and debug logs with increased verbosity, and with production mode set to true.", func() {
388 args := []string{"--zap-log-level=3", "--zap-devel=true"}
389 fromFlags.BindFlags(&fs)
390 err := fs.Parse(args)
391 Expect(err).ToNot(HaveOccurred())
392 logOut := new(bytes.Buffer)
393
394 logger := New(UseFlagOptions(&fromFlags), WriteTo(logOut))
395 logger.V(0).Info(logInfoLevel0)
396 logger.V(1).Info(logDebugLevel1)
397 logger.V(2).Info(logDebugLevel2)
398 logger.V(3).Info(logDebugLevel3)
399
400 outRaw := logOut.Bytes()
401
402 Expect(string(outRaw)).Should(ContainSubstring(logInfoLevel0))
403 Expect(string(outRaw)).Should(ContainSubstring(logDebugLevel1))
404 Expect(string(outRaw)).Should(ContainSubstring(logDebugLevel2))
405 Expect(string(outRaw)).Should(ContainSubstring(logDebugLevel3))
406 })
407 })
408
409 Context("with zap-stacktrace-level options provided", func() {
410 It("Should output stacktrace at info level, with development mode set to true.", func() {
411 args := []string{"--zap-stacktrace-level=info", "--zap-devel=true"}
412 fromFlags.BindFlags(&fs)
413 err := fs.Parse(args)
414 Expect(err).ToNot(HaveOccurred())
415 out := Options{}
416 UseFlagOptions(&fromFlags)(&out)
417
418 Expect(out.StacktraceLevel.Enabled(zapcore.InfoLevel)).To(BeTrue())
419 })
420
421 It("Should output stacktrace at error level, with development mode set to true.", func() {
422 args := []string{"--zap-stacktrace-level=error", "--zap-devel=true"}
423 fromFlags.BindFlags(&fs)
424 err := fs.Parse(args)
425 Expect(err).ToNot(HaveOccurred())
426 out := Options{}
427 UseFlagOptions(&fromFlags)(&out)
428
429 Expect(out.StacktraceLevel.Enabled(zapcore.ErrorLevel)).To(BeTrue())
430 })
431
432 It("Should output stacktrace at panic level, with development mode set to true.", func() {
433 args := []string{"--zap-stacktrace-level=panic", "--zap-devel=true"}
434 fromFlags.BindFlags(&fs)
435 err := fs.Parse(args)
436 Expect(err).ToNot(HaveOccurred())
437 out := Options{}
438 UseFlagOptions(&fromFlags)(&out)
439
440 Expect(out.StacktraceLevel.Enabled(zapcore.PanicLevel)).To(BeTrue())
441 Expect(out.StacktraceLevel.Enabled(zapcore.ErrorLevel)).To(BeFalse())
442 Expect(out.StacktraceLevel.Enabled(zapcore.InfoLevel)).To(BeFalse())
443 })
444 })
445
446 Context("with only -zap-devel flag provided", func() {
447 It("Should set dev=true.", func() {
448 args := []string{"--zap-devel=true"}
449 fromFlags.BindFlags(&fs)
450 if err := fs.Parse(args); err != nil {
451 Expect(err).ToNot(HaveOccurred())
452 }
453 out := Options{}
454 UseFlagOptions(&fromFlags)(&out)
455
456 Expect(out.Development).To(BeTrue())
457 Expect(out.Encoder).To(BeNil())
458 Expect(out.Level).To(BeNil())
459 Expect(out.StacktraceLevel).To(BeNil())
460 Expect(out.EncoderConfigOptions).To(BeNil())
461 })
462 It("Should set dev=false", func() {
463 args := []string{"--zap-devel=false"}
464 fromFlags.BindFlags(&fs)
465 if err := fs.Parse(args); err != nil {
466 Expect(err).ToNot(HaveOccurred())
467 }
468 out := Options{}
469 UseFlagOptions(&fromFlags)(&out)
470
471 Expect(out.Development).To(BeFalse())
472 Expect(out.Encoder).To(BeNil())
473 Expect(out.Level).To(BeNil())
474 Expect(out.StacktraceLevel).To(BeNil())
475 Expect(out.EncoderConfigOptions).To(BeNil())
476 })
477 })
478
479 Context("with zap-time-encoding flag provided", func() {
480 It("Should set time encoder in options", func() {
481 args := []string{"--zap-time-encoding=rfc3339"}
482 fromFlags.BindFlags(&fs)
483 err := fs.Parse(args)
484 Expect(err).ToNot(HaveOccurred())
485
486 opt := Options{}
487 UseFlagOptions(&fromFlags)(&opt)
488 opt.addDefaults()
489
490 optVal := reflect.ValueOf(opt.TimeEncoder)
491 expVal := reflect.ValueOf(zapcore.RFC3339TimeEncoder)
492
493 Expect(optVal.Pointer()).To(Equal(expVal.Pointer()))
494 })
495
496 It("Should default to 'rfc3339' time encoding", func() {
497 args := []string{""}
498 fromFlags.BindFlags(&fs)
499 err := fs.Parse(args)
500 Expect(err).ToNot(HaveOccurred())
501
502 opt := Options{}
503 UseFlagOptions(&fromFlags)(&opt)
504 opt.addDefaults()
505
506 optVal := reflect.ValueOf(opt.TimeEncoder)
507 expVal := reflect.ValueOf(zapcore.RFC3339TimeEncoder)
508
509 Expect(optVal.Pointer()).To(Equal(expVal.Pointer()))
510 })
511
512 It("Should return an error message, with unknown time-encoding", func() {
513 fs = *flag.NewFlagSet(os.Args[0], flag.ContinueOnError)
514 args := []string{"--zap-time-encoding=foobar"}
515 fromFlags.BindFlags(&fs)
516 err := fs.Parse(args)
517 Expect(err).To(HaveOccurred())
518 })
519
520 It("Should propagate time encoder to logger", func() {
521
522 iso8601Pattern := `^[0-9]{4}-[0-9]{2}-[0-9]{2}T[0-9]{2}:[0-9]{2}:[0-9]{2}.[0-9]{3}([-+][0-9]{4}|Z)`
523
524 args := []string{"--zap-time-encoding=iso8601"}
525 fromFlags.BindFlags(&fs)
526 err := fs.Parse(args)
527 Expect(err).ToNot(HaveOccurred())
528 logOut := new(bytes.Buffer)
529
530 logger := New(UseFlagOptions(&fromFlags), WriteTo(logOut))
531 logger.Info("This is a test message")
532
533 outRaw := logOut.Bytes()
534
535 res := map[string]interface{}{}
536 Expect(json.Unmarshal(outRaw, &res)).To(Succeed())
537 Expect(res["ts"]).Should(MatchRegexp(iso8601Pattern))
538 })
539 })
540
541 Context("with encoder options provided programmatically", func() {
542 It("Should set JSON Encoder, with given Millis TimeEncoder option, and MessageKey", func() {
543 logOut := new(bytes.Buffer)
544 f := func(ec *zapcore.EncoderConfig) {
545 ec.MessageKey = "MillisTimeFormat"
546 }
547 opts := func(o *Options) {
548 o.EncoderConfigOptions = append(o.EncoderConfigOptions, f)
549 }
550 log := New(UseDevMode(false), WriteTo(logOut), opts)
551 log.Info("This is a test message")
552 outRaw := logOut.Bytes()
553
554 res := map[string]interface{}{}
555 Expect(json.Unmarshal(outRaw, &res)).To(Succeed())
556
557 Expect(string(outRaw)).Should(ContainSubstring("MillisTimeFormat"))
558 })
559
560 Context("using Level()", func() {
561 var logOut *bytes.Buffer
562
563 BeforeEach(func() {
564 logOut = new(bytes.Buffer)
565 })
566
567 It("logs with negative logr level", func() {
568 By("setting up the logger")
569 logger := New(WriteTo(logOut), Level(zapcore.Level(-3)))
570 logger.V(3).Info("test 3")
571 Expect(logOut.String()).To(ContainSubstring(`"msg":"test 3"`))
572 logOut.Truncate(0)
573 logger.V(1).Info("test 1")
574 Expect(logOut.String()).To(ContainSubstring(`"msg":"test 1"`))
575 logOut.Truncate(0)
576 logger.V(4).Info("test 4")
577 Expect(logOut.String()).To(BeEmpty())
578 logger.V(-3).Info("test -3")
579 Expect(logOut.String()).To(ContainSubstring("test -3"))
580 })
581 It("does not log with positive logr level", func() {
582 By("setting up the logger")
583 logger := New(WriteTo(logOut), Level(zapcore.Level(1)))
584 logger.V(1).Info("test 1")
585 Expect(logOut.String()).To(BeEmpty())
586 logger.V(3).Info("test 3")
587 Expect(logOut.String()).To(BeEmpty())
588 })
589 })
590 })
591 })
592
View as plain text