forked from golang/glog
-
Notifications
You must be signed in to change notification settings - Fork 214
Permalink
Loading
Choose a base ref
{{ refName }}
default
Loading
Choose a head ref
{{ refName }}
default
Comparing changes
Choose two branches to see what’s changed or to start a new pull request.
If you need to, you can also or
learn more about diff comparisons.
Open a pull request
Create a new pull request by comparing changes across two branches. If you need to, you can also .
Learn more about diff comparisons here.
base repository: kubernetes/klog
base: v2.30.0
Could not load branches
Nothing to show
Loading
Could not load tags
Nothing to show
{{ refName }}
default
Loading
...
head repository: kubernetes/klog
compare: v2.40.0
Could not load branches
Nothing to show
Loading
Could not load tags
Nothing to show
{{ refName }}
default
Loading
- 12 commits
- 5 files changed
- 3 contributors
Commits on Nov 19, 2021
-
examples: use current klog, add structured logging example
Structured logging with InfoS is formatted differently than traditional output, so it's worthwhile to have an example that demostrates that. The new example didn't compile initially because an older version of klog was used. This gets avoids by always using the source from the current directory.
Configuration menu - View commit details
-
Copy full SHA for 5ecf788 - Browse repository at this point
Copy the full SHA 5ecf788View commit details
Commits on Nov 23, 2021
-
Configuration menu - View commit details
-
Copy full SHA for f930164 - Browse repository at this point
Copy the full SHA f930164View commit details
Commits on Nov 26, 2021
-
structured output: reuse buffer
There is a mechanism for allocating smallish buffers (< 256 bytes) only once and then reusing them. Doing that for the structured key/value pairs is an improvement (measured with kubernetes/kubernetes#106594): $ $GOPATH/bin/benchstat /tmp/original /tmp/reuse-buffer name old time/op new time/op delta Logging/container/structured-36 41.6µs ± 1% 41.6µs ± 1% ~ (p=1.000 n=5+5) Logging/error-value/structured-36 4.01µs ± 3% 3.37µs ± 3% -16.01% (p=0.008 n=5+5) Logging/error/structured-36 3.91µs ± 1% 3.33µs ± 3% -14.90% (p=0.008 n=5+5) Logging/simple/structured-36 3.54µs ± 3% 2.98µs ± 3% -15.77% (p=0.008 n=5+5) Logging/values/structured-36 6.83µs ± 2% 5.31µs ± 5% -22.34% (p=0.008 n=5+5) name old alloc/op new alloc/op delta Logging/container/structured-36 10.4kB ± 0% 10.5kB ± 0% +0.61% (p=0.008 n=5+5) Logging/error-value/structured-36 432B ± 0% 320B ± 0% -25.93% (p=0.008 n=5+5) Logging/error/structured-36 448B ± 0% 336B ± 0% -25.00% (p=0.008 n=5+5) Logging/simple/structured-36 408B ± 0% 296B ± 0% -27.45% (p=0.008 n=5+5) Logging/values/structured-36 777B ± 0% 505B ± 0% -35.01% (p=0.008 n=5+5) name old allocs/op new allocs/op delta Logging/container/structured-36 64.0 ± 0% 64.0 ± 0% ~ (all equal) Logging/error-value/structured-36 9.00 ± 0% 7.00 ± 0% -22.22% (p=0.008 n=5+5) Logging/error/structured-36 10.0 ± 0% 8.0 ± 0% -20.00% (p=0.008 n=5+5) Logging/simple/structured-36 8.00 ± 0% 6.00 ± 0% -25.00% (p=0.008 n=5+5) Logging/values/structured-36 16.0 ± 0% 13.0 ± 0% -18.75% (p=0.008 n=5+5)
Configuration menu - View commit details
-
Copy full SHA for ae76ae0 - Browse repository at this point
Copy the full SHA ae76ae0View commit details -
structured output: reduce usage of Sprintf
We can avoid several allocations and use faster code (= strconv.Quote) by relying less on Sprintf. $ $GOPATH/bin/benchstat /tmp/reuse-buffer /tmp/strconv name old time/op new time/op delta Logging/container/structured-36 41.6µs ± 1% 39.5µs ± 2% -5.05% (p=0.008 n=5+5) Logging/error-value/structured-36 3.37µs ± 3% 3.13µs ± 0% -7.06% (p=0.016 n=5+4) Logging/error/structured-36 3.33µs ± 3% 3.09µs ± 2% -7.10% (p=0.008 n=5+5) Logging/simple/structured-36 2.98µs ± 3% 2.86µs ± 4% ~ (p=0.095 n=5+5) Logging/values/structured-36 5.31µs ± 5% 4.77µs ± 4% -10.17% (p=0.008 n=5+5) name old alloc/op new alloc/op delta Logging/container/structured-36 10.5kB ± 0% 9.3kB ± 0% -11.01% (p=0.008 n=5+5) Logging/error-value/structured-36 320B ± 0% 312B ± 0% -2.50% (p=0.008 n=5+5) Logging/error/structured-36 336B ± 0% 312B ± 0% -7.14% (p=0.008 n=5+5) Logging/simple/structured-36 296B ± 0% 288B ± 0% -2.70% (p=0.008 n=5+5) Logging/values/structured-36 505B ± 0% 464B ± 0% -8.12% (p=0.008 n=5+5) name old allocs/op new allocs/op delta Logging/container/structured-36 64.0 ± 0% 62.0 ± 0% -3.12% (p=0.008 n=5+5) Logging/error-value/structured-36 7.00 ± 0% 6.00 ± 0% -14.29% (p=0.008 n=5+5) Logging/error/structured-36 8.00 ± 0% 6.00 ± 0% -25.00% (p=0.008 n=5+5) Logging/simple/structured-36 6.00 ± 0% 5.00 ± 0% -16.67% (p=0.008 n=5+5) Logging/values/structured-36 13.0 ± 0% 11.0 ± 0% -15.38% (p=0.008 n=5+5)
Configuration menu - View commit details
-
Copy full SHA for aac832f - Browse repository at this point
Copy the full SHA aac832fView commit details -
structured output: reorder type switch
Checking common types first is slightly faster. No difference for simple benchmarks: $ $GOPATH/bin/benchstat /tmp/strconv /tmp/reorder name old time/op new time/op delta Logging/container/structured-36 39.5µs ± 2% 39.6µs ± 1% ~ (p=1.000 n=5+5) Logging/error-value/structured-36 3.13µs ± 0% 3.14µs ± 4% ~ (p=0.730 n=4+5) Logging/error/structured-36 3.09µs ± 2% 3.13µs ± 3% ~ (p=0.548 n=5+5) Logging/simple/structured-36 2.86µs ± 4% 2.91µs ± 2% ~ (p=0.310 n=5+5) Logging/values/structured-36 4.77µs ± 4% 4.77µs ± 5% ~ (p=0.841 n=5+5) name old alloc/op new alloc/op delta Logging/container/structured-36 9.35kB ± 0% 9.35kB ± 0% ~ (p=0.095 n=5+4) Logging/error-value/structured-36 312B ± 0% 312B ± 0% ~ (all equal) Logging/error/structured-36 312B ± 0% 312B ± 0% ~ (all equal) Logging/simple/structured-36 288B ± 0% 288B ± 0% ~ (all equal) Logging/values/structured-36 464B ± 0% 464B ± 0% ~ (all equal) name old allocs/op new allocs/op delta Logging/container/structured-36 62.0 ± 0% 62.0 ± 0% ~ (all equal) Logging/error-value/structured-36 6.00 ± 0% 6.00 ± 0% ~ (all equal) Logging/error/structured-36 6.00 ± 0% 6.00 ± 0% ~ (all equal) Logging/simple/structured-36 5.00 ± 0% 5.00 ± 0% ~ (all equal) Logging/values/structured-36 11.0 ± 0% 11.0 ± 0% ~ (all equal) It's a bigger win for a real kubelet log: $ $GOPATH/bin/benchstat /tmp/strconv-kubelet /tmp/reorder-kubelet name old time/op new time/op delta Logging/v5/kubelet/structured-36 1.17s ± 2% 1.15s ± 1% -1.37% (p=0.016 n=5+5) name old alloc/op new alloc/op delta Logging/v5/kubelet/structured-36 525MB ± 0% 525MB ± 0% ~ (p=0.548 n=5+5) name old allocs/op new allocs/op delta Logging/v5/kubelet/structured-36 3.86M ± 0% 3.86M ± 0% ~ (p=0.079 n=5+5) Args: total: 310746 strings: 106904 (34%) with line breaks: 11 (0% of all arguments) with API objects: 529 (0% of all arguments) types and their number of usage: Container:529 numbers: 14563 (4%) ObjectRef: 169306 (54%) others: 19973 (6%)
Configuration menu - View commit details
-
Copy full SHA for 6749fe1 - Browse repository at this point
Copy the full SHA 6749fe1View commit details
Commits on Dec 6, 2021
-
structured logging: support key/value pairs with line breaks
The initial structured logging output (almost) always produced a single line per log message, with quoting of strings to represent line breaks as \n. This made the output hard to read (see kubernetes/kubernetes#104868). It was still possible to get line breaks when formatting a value with `%+v` and that ended up emitting line breaks; this was probably not intended. Now string values are only quoted if they contain no line break. If they do, start/end markers delimit the text which appears on its own lines, with indention to ensure that those additional lines are not accidentally treated as a new log message when they happen to contain the klog header. It also makes the output more readable. Tabs are used as indention for the value because it makes it stand out visually and because it ensures that inline ">" characters are not mistaken for the end-of-value delimiter. The result of `fmt.Sprintf("%+v")` is printed verbatim without quoting when it contains no line break, otherwise as multi-line value with delimiter and indention. Traditional output: I1112 14:06:35.783354 328441 structured_logging.go:42] someData printed using InfoF: {hello world 0} I1112 14:06:35.783472 328441 structured_logging.go:43] longData printed using InfoF: {long Multiple lines with quite a bit of text. 0} I1112 14:06:35.783483 328441 structured_logging.go:44] stringData printed using InfoF, with the message across multiple lines: long: Multiple lines with quite a bit of text. I1112 14:06:35.898176 142908 structured_logging.go:54] logData printed using InfoF: {log output from some program I0000 12:00:00.000000 123456 main.go:42] Starting E0000 12:00:01.000000 123456 main.go:43] Failed for some reason 0} Old InfoS output before this commit: I1112 14:06:35.783512 328441 structured_logging.go:50] "using InfoS" someData={Name:hello Data:world internal:0} I1112 14:06:35.783529 328441 structured_logging.go:51] "using InfoS" longData={Name:long Data:Multiple lines with quite a bit of text. internal:0} I1112 14:06:35.783549 328441 structured_logging.go:52] "using InfoS with\nthe message across multiple lines" int=1 stringData="long: Multiple\nlines\nwith quite a bit\nof text." str="another value" I1112 14:06:35.783565 328441 structured_logging.go:61] "Did something" item="foobar" I1112 14:06:35.783576 328441 structured_logging.go:63] "This is a full sentence." item="foobar" I1112 14:06:35.898278 142908 structured_logging.go:65] "using InfoS" logData={Name:log output from some program Data:I0000 12:00:00.000000 123456 main.go:42] Starting E0000 12:00:01.000000 123456 main.go:43] Failed for some reason internal:0} New InfoS output: I1126 10:31:50.378182 121736 structured_logging.go:58] "using InfoS" someData={Name:hello Data:world internal:0} I1126 10:31:50.378204 121736 structured_logging.go:59] "using InfoS" longData=< {Name:long Data:Multiple lines with quite a bit of text. internal:0} > I1126 10:31:50.378228 121736 structured_logging.go:60] "using InfoS with\nthe message across multiple lines" int=1 stringData=< long: Multiple lines with quite a bit of text. > str="another value" I1126 10:31:50.378249 121736 structured_logging.go:65] "using InfoS" logData=< {Name:log output from some program Data:I0000 12:00:00.000000 123456 main.go:42] Starting E0000 12:00:01.000000 123456 main.go:43] Failed for some reason internal:0} > Performance is the same as before in most cases. Handling of a v1.Container struct with line breaks in the output gets faster, probably because printing each line individually is more efficient than quoting. $ $GOPATH/bin/benchstat /tmp/reorder /tmp/multi-line name old time/op new time/op delta Logging/container/structured-36 39.6µs ± 1% 21.5µs ± 0% -45.82% (p=0.008 n=5+5) Logging/error-value/structured-36 3.14µs ± 4% 3.11µs ± 2% ~ (p=0.548 n=5+5) Logging/error/structured-36 3.13µs ± 3% 3.13µs ± 3% ~ (p=1.000 n=5+5) Logging/simple/structured-36 2.91µs ± 2% 2.87µs ± 2% ~ (p=0.310 n=5+5) Logging/values/structured-36 4.77µs ± 5% 4.75µs ± 4% ~ (p=1.000 n=5+5) name old alloc/op new alloc/op delta Logging/container/structured-36 9.35kB ± 0% 9.59kB ± 0% +2.59% (p=0.016 n=4+5) Logging/error-value/structured-36 312B ± 0% 312B ± 0% ~ (all equal) Logging/error/structured-36 312B ± 0% 312B ± 0% ~ (all equal) Logging/simple/structured-36 288B ± 0% 288B ± 0% ~ (all equal) Logging/values/structured-36 464B ± 0% 464B ± 0% ~ (all equal) name old allocs/op new allocs/op delta Logging/container/structured-36 62.0 ± 0% 63.0 ± 0% +1.61% (p=0.008 n=5+5) Logging/error-value/structured-36 6.00 ± 0% 6.00 ± 0% ~ (all equal) Logging/error/structured-36 6.00 ± 0% 6.00 ± 0% ~ (all equal) Logging/simple/structured-36 5.00 ± 0% 5.00 ± 0% ~ (all equal) Logging/values/structured-36 11.0 ± 0% 11.0 ± 0% ~ (all equal)
Configuration menu - View commit details
-
Copy full SHA for fafe98e - Browse repository at this point
Copy the full SHA fafe98eView commit details -
Merge pull request #273 from pohly/multi-line-value-2
structured logging: support values with line breaks
Configuration menu - View commit details
-
Copy full SHA for 7fa0f3b - Browse repository at this point
Copy the full SHA 7fa0f3bView commit details
Commits on Dec 10, 2021
-
This wasn't covered before. At first glance the different formatting of the individual objects (no quotation marks) looks a bit odd compared to how KObj is formatted, but that's what we have right now.
Configuration menu - View commit details
-
Copy full SHA for 39919d8 - Browse repository at this point
Copy the full SHA 39919d8View commit details -
Merge pull request #272 from astraw99/fix-log-panic
Fix klog lock release on panic error
Configuration menu - View commit details
-
Copy full SHA for 55872ed - Browse repository at this point
Copy the full SHA 55872edView commit details
Commits on Dec 14, 2021
-
It is needed in Kubernetes for code like this (from k8s.io/apiserver/pkg/server/httplog/httplog.go): // Log is intended to be called once at the end of your request handler, via defer func (rl *respLogger) Log() { ... klog.V(withLoggingLevel).InfoSDepth(1, "HTTP", keysAndValues...) } Without InfoSDepth as method for Verbose, such code has to use klog.InfoSDepth, which records the message with v=0 in JSON output. This is the wrong verbosity for this debug message. We don't need Verbose.ErrorSDepth (error messages have no verbosity) and also no Verbose.Info[f]Depth (when touching code, it should be rewritten to use Verbose.InfoSDepth instead)
Configuration menu - View commit details
-
Copy full SHA for b605dee - Browse repository at this point
Copy the full SHA b605deeView commit details
Commits on Dec 17, 2021
-
Merge pull request #276 from pohly/kobjs-format-test
add format test for KObjs
Configuration menu - View commit details
-
Copy full SHA for 6963321 - Browse repository at this point
Copy the full SHA 6963321View commit details -
Merge pull request #277 from pohly/v-infos
add Verbose.InfoSDepth
Configuration menu - View commit details
-
Copy full SHA for 9248e72 - Browse repository at this point
Copy the full SHA 9248e72View commit details
Loading
This comparison is taking too long to generate.
Unfortunately it looks like we can’t render this comparison for you right now. It might be too big, or there might be something weird with your repository.
You can try running this command locally to see the comparison on your machine:
git diff v2.30.0...v2.40.0