search

kubernetes-sigs / kube-scheduler-wasm-extension

All the things to make the scheduler extendable with wasm.
Apache License 2.0
83 stars 16 forks source link

Add klog.Info/Error support #67

Closed codefromthecrypt closed 9 months ago

codefromthecrypt commented 9 months ago

What type of PR is this?

/kind feature

What this PR does / why we need it:

This begins klog support with the simplest api used in plugins: klog.Info, klog.InfoS, klog.Error and klog.ErrorS

Which issue(s) this PR fixes:

NONE

Special notes for your reviewer:

Does this PR introduce a user-facing change?

NONE

What are the benchmark results of this change?

Performance of Simple is wild because it uses the default GC and the plugin is heavy due to protos. Advanced uses nottinygc and also separates out code that uses imports so that they can be more easily tested. These notes are in the READMEs.

The main thing here is that performance of Advanced/Run is the same when logging is disabled, and it drops 13% (7us) per Run when enabled. This shows the deferred stringification works, but also shows logging has a measurable cost even when only a couple times.

goos: darwin
goarch: arm64
pkg: sigs.k8s.io/kube-scheduler-wasm-extension/internal/e2e/scheduler
                                       │  before.txt  │              now.txt               │
                                       │    sec/op    │    sec/op     vs base              │
Example_NodeNumber/Simple/New-12         63.64m ±  3%   62.56m ±  0%       ~ (p=0.065 n=6)
Example_NodeNumber/Simple/Run-12         223.0µ ± 87%   294.2µ ± 32%       ~ (p=0.240 n=6)
Example_NodeNumber/Advanced/New-12       76.34m ±  2%   73.95m ±  1%  -3.13% (p=0.002 n=6)
Example_NodeNumber/Advanced/Run-12       46.71µ ±  3%   47.57µ ±  1%       ~ (p=0.065 n=6)
Example_NodeNumber/Simple_Log/New-12                    62.40m ±  1%
Example_NodeNumber/Simple_Log/Run-12                    176.6µ ± 29%
Example_NodeNumber/Advanced_Log/New-12                  73.83m ±  1%
Example_NodeNumber/Advanced_Log/Run-12                  54.63µ ±  1%
geomean                                  2.667m         2.706m        +6.35%
codefromthecrypt commented 9 months ago

going to try to add InfoS/ErrorS now. mostly an exercise in copying logic and backfilling tests

codefromthecrypt commented 9 months ago

polished and stubbed structured logging.

next step: implement it

sanposhiho commented 9 months ago

I like this approach. Please go ahead 👍

codefromthecrypt commented 9 months ago

OK I will finish this up, but I won't have time to implement the structured log in the same PR (will leave the signatures for a later change). Will mark ready for review when ready.

codefromthecrypt commented 9 months ago

69 should go first

codefromthecrypt commented 9 months ago

Added the commit from #69 to proceed further. Will try to finish structured logging in the same PR

codefromthecrypt commented 9 months ago

Ok I've gotten this far, but something's wrong with k/v on the host side. Will look into it later

I0802 15:18:53.788082   34631 host.go:219] NodeNumberArgs is successfully applied
I0802 15:18:53.788393   34631 host.go:264] "execute PreScore on NodeNumber plugin" pod="(MISSING)"
I0802 15:18:53.788411   34631 host.go:264] "execute Score on NodeNumber plugin" pod="(MISSING)"
codefromthecrypt commented 9 months ago

So, what's left here is..

evacchi commented 9 months ago

I pushed 4 distinct commits so that you can pick any of these changes if you think they help:

  1. fix for the logging issue (just a misconfigured test)
  2. capture klog and add the assertions
  3. add examples -- but I am not sure I did what you had in mind: the output is empty as it was for the other examples
  4. I tried to draft another plugin under all.go for tinygo logPlugin which is just the same as params except it should also log them, but I did not figure out where to put the actual test cases; also it felt a bit redundant because of (2); but maybe you had something different in mind

feel free to drop all of them if they are not useful!

codefromthecrypt commented 9 months ago

Thanks for all the help @evacchi I will go through and do any buttoning up once #69 merges, which might be monday due to some of us having typhoon displacement ;)

codefromthecrypt commented 9 months ago

squashed work so far and will move this to the finish line soon. Thanks a lot @evacchi!

codefromthecrypt commented 9 months ago

@sanposhiho I'm marking ready for review even if I have some test cases to backfill. You can see in the PR desc that logging enabled vs disabled makes a difference in performance, which means our ABI is working! Thanks to @evacchi for the collaboration on this.

codefromthecrypt commented 9 months ago

ok ready. only other refactoring will be separate PR as I want to see if we can avoid using "wat" format too much.

The main thing here is we can see that the advanced plugin perf is within the margin of error (comparable to before), and when logging is switched on, it drops 13% (7us) per run, which makes sense as logging is expensive.

k8s-ci-robot commented 9 months ago

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: codefromthecrypt, sanposhiho

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

The pull request process is described here

Needs approval from an approver in each of these files: - ~~[OWNERS](https://github.com/kubernetes-sigs/kube-scheduler-wasm-extension/blob/main/OWNERS)~~ [codefromthecrypt,sanposhiho] Approvers can indicate their approval by writing `/approve` in a comment Approvers can cancel approval by writing `/approve cancel` in a comment