1# Example
2
3This directory includes example logger binaries which show how to use
4component-base/logs and what effect the different command line options have.
5Like most Kubernetes components, `cmd` uses Cobra and pflags. `stdlib` uses
6just plain Go libraries. `test` contains a unit test with per-test output.
7
8Below we can see examples of how some features work.
9
10## Default
11
12Run:
13```console
14go run ./staging/src/k8s.io/component-base/logs/example/cmd/logger.go
15```
16
17Expected output:
18```
19I0329 11:36:38.734334 99095 logger.go:44] "Oops, I shouldn't be logging yet!"
20This is normal output via stdout.
21This is other output via stderr.
22I0329 11:36:38.734575 99095 logger.go:76] Log using Infof, key: value
23I0329 11:36:38.734592 99095 logger.go:77] "Log using InfoS" key="value"
24E0329 11:36:38.734604 99095 logger.go:79] Log using Errorf, err: fail
25E0329 11:36:38.734619 99095 logger.go:80] "Log using ErrorS" err="fail"
26I0329 11:36:38.734653 99095 logger.go:87] "Now the default logger is set, but using the one from the context is still better."
27I0329 11:36:38.734693 99095 logger.go:94] "runtime" duration="1m0s"
28I0329 11:36:38.734710 99095 logger.go:95] "another runtime" duration="1m0s"
29```
30
31## JSON
32
33Run:
34```console
35go run ./staging/src/k8s.io/component-base/logs/example/cmd/logger.go --logging-format json
36```
37
38Expected output:
39```
40I0329 11:38:01.782592 99945 logger.go:44] "Oops, I shouldn't be logging yet!"
41This is normal output via stdout.
42This is other output via stderr.
43{"ts":1648546681782.9036,"caller":"cmd/logger.go:76","msg":"Log using Infof, key: value\n","v":0}
44{"ts":1648546681782.9392,"caller":"cmd/logger.go:77","msg":"Log using InfoS","v":0,"key":"value"}
45{"ts":1648546681782.9763,"caller":"cmd/logger.go:79","msg":"Log using Errorf, err: fail\n"}
46{"ts":1648546681782.9915,"caller":"cmd/logger.go:80","msg":"Log using ErrorS","err":"fail"}
47{"ts":1648546681783.0364,"caller":"cmd/logger.go:87","msg":"Now the default logger is set, but using the one from the context is still better.","v":0}
48{"ts":1648546681783.1091,"caller":"cmd/logger.go:94","msg":"runtime","v":0,"duration":"1m0s"}
49{"ts":1648546681783.1257,"caller":"cmd/logger.go:95","msg":"another runtime","v":0,"duration":"1h0m0s","duration":"1m0s"}
50```
51
52## Verbosity
53
54```console
55go run ./staging/src/k8s.io/component-base/logs/example/cmd/logger.go -v1
56```
57
58The expected output now includes `Log less important message`:
59```
60I0329 11:38:23.145695 100190 logger.go:44] "Oops, I shouldn't be logging yet!"
61This is normal output via stdout.
62This is other output via stderr.
63I0329 11:38:23.145944 100190 logger.go:76] Log using Infof, key: value
64I0329 11:38:23.145961 100190 logger.go:77] "Log using InfoS" key="value"
65E0329 11:38:23.145973 100190 logger.go:79] Log using Errorf, err: fail
66E0329 11:38:23.145989 100190 logger.go:80] "Log using ErrorS" err="fail"
67I0329 11:38:23.146017 100190 logger.go:83] Log less important message
68I0329 11:38:23.146034 100190 logger.go:87] "Now the default logger is set, but using the one from the context is still better."
69I0329 11:38:23.146074 100190 logger.go:94] "runtime" duration="1m0s"
70I0329 11:38:23.146091 100190 logger.go:95] "another runtime" duration="1m0s"
71```
72
73## Contextual logging
74
75Contextual logging enables the caller of the function to add a string prefix
76and additional key/value pairs to a logger and then pass the updated logger
77into functions via a `context` parameter.
78
79At the moment, this functionality is controlled in Kubernetes with the
80`ContextualLogging` feature gate and disabled by
81default. `klog.LoggerWithValues`, `klog.LoggerWithName`, `klog.NewContext` just
82return the original instance when contextual logging is
83disabled. `klog.FromContext` doesn't check the context for a logger and instead
84returns the global logger.
85
86```console
87go run ./staging/src/k8s.io/component-base/logs/example/cmd/logger.go --feature-gates ContextualLogging=true
88```
89
90The expected output now includes `example` (added by caller) and `myname`
91(added by callee) as prefix and the caller's `foo="bar"` key/value pair:
92```
93I0329 11:47:36.830458 101057 logger.go:44] "Oops, I shouldn't be logging yet!"
94This is normal output via stdout.
95This is other output via stderr.
96I0329 11:47:36.830715 101057 logger.go:76] Log using Infof, key: value
97I0329 11:47:36.830731 101057 logger.go:77] "Log using InfoS" key="value"
98E0329 11:47:36.830745 101057 logger.go:79] Log using Errorf, err: fail
99E0329 11:47:36.830760 101057 logger.go:80] "Log using ErrorS" err="fail"
100I0329 11:47:36.830795 101057 logger.go:87] "Now the default logger is set, but using the one from the context is still better."
101I0329 11:47:36.830841 101057 logger.go:94] "example/myname: runtime" foo="bar" duration="1m0s"
102I0329 11:47:36.830859 101057 logger.go:95] "example: another runtime" foo="bar" duration="1m0s"
103```
View as plain text