Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

RFC: faster implementation of KObj #261

Closed
wants to merge 2 commits into from
Closed

Conversation

pohly
Copy link

@pohly pohly commented Sep 7, 2021

What this PR does / why we need it:

KObj always does some work (construct ObjectReference) which might not be needed later on and also is more expensive to copy.

An alternative implementation (tentatively called KObj2 at the moment) just stores the interface and uses it later on demand.

Special notes for your reviewer:

When testing with v1.Pod, the benchmark gives:

$ go test -bench=. ./benchmark
goos: linux
goarch: amd64
pkg: k8s.io/klog/v2/benchmark
cpu: Intel(R) Core(TM) i9-7980XE CPU @ 2.60GHz
BenchmarkKObjByPointer-36           	 3013046	       383.2 ns/op
BenchmarkKObj2ByPointer-36          	 3076359	       365.3 ns/op
BenchmarkSkipObjByPointer-36        	 5570828	       234.7 ns/op
BenchmarkSkipObj2ByPointer-36       	 6675914	       178.9 ns/op
BenchmarkDiscardObjByPointer-36     	 5869794	       213.2 ns/op
BenchmarkDiscardObj2ByPointer-36    	 7232146	       163.3 ns/op
PASS
ok  	k8s.io/klog/v2/benchmark	8.829s

The commit which adds testing with v1.Pod shouldn't be merged because we probably don't want to depend on the k8s API. But it's more realistic than the benchmark with a fake object from the first commit, although that also shows an advantage.

Release note:

TBD

Creating a KObjectReference creates work (allocation, string copy) that might
not be needed when the log message is not actually emitted. An alternative
implementation where KObj2 just keeps the interface and calls its only when
needed is usually faster.
@k8s-ci-robot k8s-ci-robot added cncf-cla: yes Indicates the PR's author has signed the CNCF CLA. size/L Denotes a PR that changes 100-499 lines, ignoring generated files. labels Sep 7, 2021
@k8s-ci-robot
Copy link

[APPROVALNOTIFIER] This PR is NOT APPROVED

This pull-request has been approved by: pohly
To complete the pull request process, please assign serathius after the PR has been reviewed.
You can assign the PR to them by writing /assign @serathius in a comment when ready.

The full list of commands accepted by this bot can be found here.

Needs approval from an approver in each of these files:

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

@pohly
Copy link
Author

pohly commented Sep 7, 2021

I'm just sharing to document the alternative approach. I'm not sure whether adding it to the klog API now is still worthwhile. It cannot replace the existing KObj (API break!), so we would have to carry both.

@neolit123
Copy link
Member

KObj always does some work (construct ObjectReference) which might not be needed later on and also is more expensive to copy.

make sense to me.

leaving review to sig-instrumentation.
/uncc

@k8s-ci-robot k8s-ci-robot removed the request for review from neolit123 September 7, 2021 15:10
@serathius
Copy link

serathius commented Sep 7, 2021

Recommend using https://github.com/golang/perf/tree/master/cmd/benchstat when analysing performance improvements in golang. This article explains why and how to use it https://about.sourcegraph.com/go/gophercon-2019-optimizing-go-code-without-a-blindfold/#Benchmarks-3-Statistics

@pohly
Copy link
Author

pohly commented Sep 9, 2021

"benchstat" is indeed useful. I reorganized the benchmark so that it just has cases with KObj which then can be run as-is or with KObj replaced by KObj2: https://github.com/pohly/klog/commits/testinglogger-kobj2

I also included zapr.

Here the results, including allocs (via go test -bench=. -count=5 -benchmem ./benchmark/):

name            old time/op    new time/op    delta
String-36          388ns ± 3%     388ns ± 2%     ~     (p=1.000 n=5+5)
Klog-36           5.00µs ± 3%    4.95µs ± 6%     ~     (p=0.389 n=5+5)
KlogSkipped-36     234ns ± 1%     178ns ± 2%  -23.87%  (p=0.008 n=5+5)
Discard-36         204ns ± 3%     148ns ± 1%  -27.09%  (p=0.008 n=5+5)
Zap-36            1.77µs ± 2%    1.61µs ± 1%   -9.29%  (p=0.008 n=5+5)
ZapSkipped-36      245ns ± 2%     191ns ± 4%  -22.19%  (p=0.008 n=5+5)

name            old alloc/op   new alloc/op   delta
String-36          64.0B ± 0%     64.0B ± 0%     ~     (all equal)
Klog-36             584B ± 0%      568B ± 0%   -2.81%  (p=0.008 n=5+5)
KlogSkipped-36     64.0B ± 0%     48.0B ± 0%  -25.00%  (p=0.008 n=5+5)
Discard-36         48.0B ± 0%     32.0B ± 0%  -33.33%  (p=0.008 n=5+5)
Zap-36              193B ± 0%      177B ± 0%   -8.29%  (p=0.008 n=5+5)
ZapSkipped-36      64.0B ± 0%     48.0B ± 0%  -25.00%  (p=0.008 n=5+5)

name            old allocs/op  new allocs/op  delta
String-36           3.00 ± 0%      3.00 ± 0%     ~     (all equal)
Klog-36             14.0 ± 0%      14.0 ± 0%     ~     (all equal)
KlogSkipped-36      2.00 ± 0%      2.00 ± 0%     ~     (all equal)
Discard-36          2.00 ± 0%      2.00 ± 0%     ~     (all equal)
Zap-36              6.00 ± 0%      6.00 ± 0%     ~     (all equal)
ZapSkipped-36       2.00 ± 0%      2.00 ± 0%     ~     (all equal)

return ObjectRef2{KMetadata: obj}
}

type ObjectRef2 struct {

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ObjectRef is expected to serialized to both text (using Stringer interface) and json (using Marshaler interface). ObjectRef annotates fields and uses default json marshaller. For ObjectRef2 we need to implement our own MarshalJSON method.

Can you add MarshalJSON to KObj2 and also benchmark it?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ObjectRef is expected to serialized to both text (using Stringer interface) and json (using Marshaler interface).

That doesn't work for json. Zap prefers the String method over MarshalJSON over marshalling structs, see my comment in #240 (comment)

There are no test cases with KObj in https://github.com/kubernetes/kubernetes/blob/master/staging/src/k8s.io/component-base/logs/json/klog_test.go which might explain why this hasn't shown up before.

Can you add MarshalJSON to KObj2 and also benchmark it?

I already did that in the https://github.com/pohly/klog/commits/testinglogger-kobj2 branch that I used for benchmarking, but because it never gets called, it didn't make a difference (I also ran that comparison as benchmark, just to be sure).

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let's discuss the desired output for KObj in kubernetes/kubernetes#104877

@k8s-ci-robot k8s-ci-robot added the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Oct 22, 2021
@k8s-ci-robot
Copy link

@pohly: PR needs rebase.

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

@pohly
Copy link
Author

pohly commented Dec 10, 2021

/close

I'll come back to this as part of kubernetes/enhancements#3078. I've created a tracking issue at kubernetes/kubernetes#106945

@k8s-ci-robot
Copy link

@pohly: Closed this PR.

In response to this:

/close

I'll come back to this as part of kubernetes/enhancements#3078. I've created a tracking issue at kubernetes/kubernetes#106945

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
cncf-cla: yes Indicates the PR's author has signed the CNCF CLA. needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. size/L Denotes a PR that changes 100-499 lines, ignoring generated files.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

4 participants