k8s.io/client-go/tools/[events|record]: support context #120729

pohly · 2023-09-18T09:46:15Z

What type of PR is this?

/kind cleanup

What this PR does / why we need it:

In events, using StartRecordingToSinkWithContext instead of StartRecordingToSink and StartLogging instead of StartStructuredLogging has several advantages:

Spawned goroutines no longer get stuck for extended periods of time during shutdown when passing in a context that gets canceled.
Log output can be directed towards a specific logger instead of the global default, for example one which writes to a testing.T instance.
The new methods return an error when something went wrong instead of merely recording the error.

That last point is the reason for deprecating the old methods instead of merely adding new alternatives.

In record, setting a context when constructing an EventBroadcaster makes calling Shutdown
optional. It can also be used to specify the logger.

The EventRecorder doesn't need a context, so its construction just takes a
logger as optional parameter.

Special notes for your reviewer:

Does this PR introduce a user-facing change?

client-go: k8s.io/client-go/tools events and record packages have new APIs for specifying a context and logger

pohly · 2023-09-18T10:42:56Z

Once this is merged, I intend to update existing code to use the modified APIs. I can also include that in this PR, if it is preferred.

pohly · 2023-09-18T12:03:00Z

/cc @dgrisonnet

pohly · 2023-09-18T12:23:17Z

staging/src/k8s.io/client-go/tools/events/event_recorder.go

@@ -45,19 +45,20 @@ func (recorder *recorderImpl) Eventf(regarding runtime.Object, related runtime.O
 	message := fmt.Sprintf(note, args...)
 	refRegarding, err := reference.GetReference(recorder.scheme, regarding)
 	if err != nil {
-		klog.Errorf("Could not construct reference to: '%#v' due to: '%v'. Will not report event: '%v' '%v' '%v'", regarding, err, eventtype, reason, message)
+		// TODO: extend Eventf with ctx parameter.


There are currently 226 such calls. That's a lot, but IMHO it is the right thing to do. Otherwise the error will not get logged as part of the current activity which triggered the event.

I prefer context over klog.Logger here because if we ever need to do some real work inside Eventf, that context would provide the deadline for it.

Also an important point in favor of context: the logger is normally not needed, so the usual argument against context when a logger is needed (the extra lookup) doesn't apply.

I wonder if it is really worth adding a context to Eventf. We have 226 such calls in-tree, but it will also impact the consumers of client-go. Realistically, this change will impact the majority of the operators that are in the wild today.

here because if we ever need to do some real work inside Eventf

I don't think we will ever need to do anything more than create an Event object here. All the aggregation and apiserver related logics are done at the broadcaster's level today and I don't think this is bound to change.
Also, with the changes you made from this PR, we will now be able to cancel broadcasting from the context, which isn't something we could do before.

The alternative is to add an EventfWithLogger which takes a klog.Logger as first parameter. Using that function is optional, i.e. Eventf will not get deprecated, but code which cares about getting the error log messages recorded "correctly" have an API to do it.

Because it's not a context, Eventf can be implemented as EventfWithLogger(klog.Background(), ...). If we needed a context, Eventf would remain incomplete because it would forever have to use context.TODO.

I tried a different approach: EventRecorder.WithContext creates a new EventRecorder which holds a context for the Eventf call. I chose that approach because record.EventRecorder contains three calls which all would have needed separate variants with an explicit ctx parameter.

Extending a published interface that could have been implemented elsewhere is always risky because it is an API break. I think it's safe in this case.

@dgrisonnet: what do you think?

Change of plan... there are enough "fake EventSource" implementations that extending that interface is annoying. I changed the code so that EventSource is unchanged and added EventSourceContext as extension of it. To avoid type casting, constructors return that. This leads to an API change in EventBroadcaster but perhaps that one is only used and not implemented by clients?

Code using the API still works as before:

var recorder EventRecorder recorder = broadcaster.NewRecorder(...)

I'm still a bit unsure whether ctx or logger is a better parameter. Some code calling Eventf calls has a logger, some a context. Ideally, passing one or the other would be possible without additional overhead. I'll explore that...

Passing an interface instead of plain ctx or logger turned out to be too complicated. As some code only has a logger and changing that code would be more complicated than adding klog.FromContext in code which has a ctx, let's just use logger.

I've pushed the version which uses WithLogger instead of WithContext.

Converting existing code is often as easy as s/recorder record.EventRecorder/recorder record.EventRecorderLogger/ and s/recorder.Event/recorder.WithLogger(logger).Event/. I converted two controllers as a trial, but won't include those changes in this PR - that can come separately.

I am fine with your last approach with WithLogger. It feels a bit odd to have the logger in a context in the broadcaster and a logger directly in the recorder, but since the recorder doesn't need a context, I think it makes sense.

alexzielenski · 2023-09-19T18:52:26Z

/sig instrumentation

k8s-ci-robot · 2023-09-19T18:52:29Z

@alexzielenski: Those labels are not set on the issue: sig/apimachinery

In response to this:

/sig instrumentation
/remove-sig apimachinery

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.

alexzielenski · 2023-09-19T18:52:56Z

/remove-sig api-machinery

wojtek-t · 2023-09-21T09:06:42Z

staging/src/k8s.io/client-go/tools/record/event.go

+		for {
+			select {
+			case <-e.cancelationCtx.Done():
+				watcher.Stop()


We're risking double-stopping here if the called would decide to stop it too.

And that is not safe?

It seems here it is:
https://github.com/kubernetes/kubernetes/blob/master/staging/src/k8s.io/apimachinery/pkg/watch/mux.go#L316

[I just saw things across codebase, where Stop() isn't necessarily idempotent...]

Yes, definitely worth checking.

dgrisonnet · 2023-09-21T09:46:48Z

staging/src/k8s.io/client-go/tools/events/event_recorder.go

@@ -45,19 +45,20 @@ func (recorder *recorderImpl) Eventf(regarding runtime.Object, related runtime.O
 	message := fmt.Sprintf(note, args...)
 	refRegarding, err := reference.GetReference(recorder.scheme, regarding)
 	if err != nil {
-		klog.Errorf("Could not construct reference to: '%#v' due to: '%v'. Will not report event: '%v' '%v' '%v'", regarding, err, eventtype, reason, message)
+		// TODO: extend Eventf with ctx parameter.


I wonder if it is really worth adding a context to Eventf. We have 226 such calls in-tree, but it will also impact the consumers of client-go. Realistically, this change will impact the majority of the operators that are in the wild today.

here because if we ever need to do some real work inside Eventf

I don't think we will ever need to do anything more than create an Event object here. All the aggregation and apiserver related logics are done at the broadcaster's level today and I don't think this is bound to change.
Also, with the changes you made from this PR, we will now be able to cancel broadcasting from the context, which isn't something we could do before.

dgrisonnet · 2023-09-21T09:53:03Z

staging/src/k8s.io/client-go/tools/record/event.go

+
+type config struct {
+	CorrelatorOptions
+	context.Context


I like the fact that you added a context here. Although it is usually not recommend to have context in structs, here I think it makes sense since Eventf doesn't really have a scope as it is delegating all the work to the broadcaster.
This makes even more sense in future events/v1 implementation since we wanted to add a backoff mechanism to the broadcaster to avoid burst of Events on the apiserver.

dashpole · 2023-09-21T16:32:27Z

/triage accepted
/assign @dgrisonnet
/priority important-soon

pohly · 2023-09-26T08:18:00Z

staging/src/k8s.io/client-go/tools/internal/events/interfaces.go

+// Package internal is needed to break an import cycle: record.EventRecorderAdapter
+// needs this interface definition to implement it, but event.NewEventBroadcasterAdapter
+// needs record.NewBroadcaster. Therefore this interface cannot be in event/interfaces.go.
+package internal


It's unfortunate that this internal package is needed.

This could be avoided by moving record.EventRecorderAdapter into events, but that's going to break all code currently expecting it in record. I'm not sure why it was added there in the first place, but it is what it is now...

The cyclic dependency is caused by the fact that core/v1 needs to be compatible with events/v1 and events/v1 with core/v1.
But I don't know why this wasn't added to the events package instead of record. Might be an oversight.

Either way, I think it is fine to have an internal package because of this limitation

Using StartRecordingToSinkWithContext instead of StartRecordingToSink and StartLogging instead of StartStructuredLogging has several advantages: - Spawned goroutines no longer get stuck for extended periods of time during shutdown when passing in a context that gets canceled. - Log output can be directed towards a specific logger instead of the global default, for example one which writes to a testing.T instance. - The new methods return an error when something went wrong instead of merely recording the error. That last point is the reason for deprecating the old methods instead of merely adding new alternatives. Setting a context when constructing an EventBroadcaster makes calling Shutdown optional. It can also be used to specify the logger. Both EventRecorder interfaces in tools/events and tools/record now have a WithLogger helper. Using that method is optional, but recommended to support contextual logging properly. Without it, errors that occur while emitting an event are not associated with the caller.

Because the EventBroadcaster code now has a a context, changing the EventSink interface so that the methods accepts a context instead of using context.TODO becomes possible.

dgrisonnet · 2023-09-28T13:29:10Z

staging/src/k8s.io/client-go/tools/events/event_broadcaster.go

+// StartLogging starts sending events received from this EventBroadcaster to the structured logger.
+// To adjust verbosity, use the logger's V method (i.e. pass `logger.V(3)` instead of `logger`).
+// The returned function can be ignored or used to stop recording, if desired.
+func (e *eventBroadcasterImpl) StartLogging(logger klog.Logger) (func(), error) {


Would it make sense to propagate this logger inside of the broadcaster context?

There is only one broadcaster context, and it was set up earlier already. I don't think we should change it.

Besides, StartLogging might be called more than once and each invocation starts recording events to some other logger. This might never be done, but it shows the conceptual difference: this logger really is only for this particular call.

dgrisonnet · 2023-09-29T13:13:52Z

This looks good to me.

@wojtek-t could you have a second look at this PR when you get the chance?

wojtek-t · 2023-10-02T12:59:54Z

/lgtm
/approve

k8s-ci-robot · 2023-10-02T13:00:01Z

LGTM label has been added.

Git tree hash: 491322d8d300b0d4d72803b1e774e4945c60f7c7

pohly · 2023-10-02T16:23:27Z

/assign @sttts

For dependency approval. The new internal module shows up in vendor/modules.txt, that's all.

sttts · 2023-10-04T06:38:46Z

/approve

k8s-ci-robot · 2023-10-04T06:39:11Z

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: pohly, sttts, wojtek-t

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:

~~hack/OWNERS~~ [pohly,sttts,wojtek-t]
~~staging/src/k8s.io/client-go/OWNERS~~ [sttts,wojtek-t]
~~vendor/OWNERS~~ [sttts]

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

pohly · 2023-10-04T12:37:20Z

/retest

pohly mentioned this pull request Sep 18, 2023

rewrite signature of function StartEventWatcher #111545

Merged

k8s-ci-robot added sig/api-machinery Categorizes an issue or PR as relevant to SIG API Machinery. and removed do-not-merge/needs-sig Indicates an issue or PR lacks a `sig/foo` label and requires one. labels Sep 18, 2023

pohly mentioned this pull request Sep 18, 2023

Support structured and contextual logging kubernetes-sigs/sig-storage-lib-external-provisioner#154

Merged

k8s-ci-robot requested review from RainbowMango and serathius September 18, 2023 09:47

pohly mentioned this pull request Sep 18, 2023

contextual logging kubernetes/enhancements#3077

Open

12 tasks

k8s-ci-robot requested a review from dgrisonnet September 18, 2023 12:03

pohly force-pushed the events-context branch from b4a382e to 9973c39 Compare September 18, 2023 12:18

pohly commented Sep 18, 2023

View reviewed changes

k8s-ci-robot added the sig/instrumentation Categorizes an issue or PR as relevant to SIG Instrumentation. label Sep 19, 2023

k8s-ci-robot removed the sig/api-machinery Categorizes an issue or PR as relevant to SIG API Machinery. label Sep 19, 2023

wojtek-t reviewed Sep 21, 2023

View reviewed changes

wojtek-t self-assigned this Sep 21, 2023

dgrisonnet reviewed Sep 21, 2023

View reviewed changes

k8s-ci-robot assigned dgrisonnet Sep 21, 2023

k8s-ci-robot added the triage/accepted Indicates an issue or PR is ready to be actively worked on. label Sep 21, 2023

pohly force-pushed the events-context branch from 9973c39 to 4e5b1c7 Compare September 26, 2023 08:09

k8s-ci-robot added the sig/api-machinery Categorizes an issue or PR as relevant to SIG API Machinery. label Sep 26, 2023

pohly force-pushed the events-context branch from 4e5b1c7 to 28d4989 Compare September 26, 2023 08:15

pohly commented Sep 26, 2023

View reviewed changes

pohly force-pushed the events-context branch 3 times, most recently from 4aa0c3f to 4e27815 Compare September 27, 2023 06:18

pohly added 2 commits September 27, 2023 09:06

k8s.io/client-go/tools/events: pass context into EventSink methods

5dc540f

Because the EventBroadcaster code now has a a context, changing the EventSink interface so that the methods accepts a context instead of using context.TODO becomes possible.

pohly force-pushed the events-context branch from 4e27815 to 5dc540f Compare September 27, 2023 07:06

dgrisonnet reviewed Sep 28, 2023

View reviewed changes

k8s-ci-robot added the lgtm "Looks good to me", indicates that a PR is ready to be merged. label Oct 2, 2023

k8s-ci-robot assigned sttts Oct 2, 2023

k8s-ci-robot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Oct 4, 2023

k8s-ci-robot merged commit f936f69 into kubernetes:master Oct 4, 2023
15 checks passed

k8s-ci-robot added this to the v1.29 milestone Oct 4, 2023

pohly mentioned this pull request Dec 7, 2023

dra helper: check and enhance error messages #122214

Open

mengjiao-liu mentioned this pull request Dec 13, 2023

kube-controller-manager: readjust log verbosity #122293

Merged

tesshuflower mentioned this pull request Apr 5, 2024

Tflow kubernetes v0.29.3 backube/volsync#1200

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

k8s.io/client-go/tools/[events|record]: support context #120729

k8s.io/client-go/tools/[events|record]: support context #120729

pohly commented Sep 18, 2023

pohly commented Sep 18, 2023

pohly commented Sep 18, 2023

pohly Sep 18, 2023

pohly Sep 18, 2023

dgrisonnet Sep 21, 2023

pohly Sep 21, 2023

pohly Sep 26, 2023

pohly Sep 26, 2023 •

edited

pohly Sep 26, 2023

pohly Sep 26, 2023

pohly Sep 27, 2023

dgrisonnet Sep 28, 2023

alexzielenski commented Sep 19, 2023 •

edited

k8s-ci-robot commented Sep 19, 2023

alexzielenski commented Sep 19, 2023

wojtek-t Sep 21, 2023

pohly Sep 21, 2023

wojtek-t Sep 21, 2023

pohly Sep 26, 2023

dgrisonnet Sep 21, 2023

dgrisonnet Sep 21, 2023

dashpole commented Sep 21, 2023

pohly Sep 26, 2023

dgrisonnet Sep 28, 2023

dgrisonnet Sep 28, 2023

dgrisonnet Sep 28, 2023

pohly Sep 29, 2023

dgrisonnet commented Sep 29, 2023

wojtek-t commented Oct 2, 2023

k8s-ci-robot commented Oct 2, 2023

pohly commented Oct 2, 2023

sttts commented Oct 4, 2023

k8s-ci-robot commented Oct 4, 2023

pohly commented Oct 4, 2023

k8s.io/client-go/tools/[events|record]: support context #120729

k8s.io/client-go/tools/[events|record]: support context #120729

Conversation

pohly commented Sep 18, 2023

What type of PR is this?

What this PR does / why we need it:

Special notes for your reviewer:

Does this PR introduce a user-facing change?

pohly commented Sep 18, 2023

pohly commented Sep 18, 2023

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

pohly Sep 26, 2023 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

alexzielenski commented Sep 19, 2023 • edited

k8s-ci-robot commented Sep 19, 2023

alexzielenski commented Sep 19, 2023

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dashpole commented Sep 21, 2023

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dgrisonnet commented Sep 29, 2023

wojtek-t commented Oct 2, 2023

k8s-ci-robot commented Oct 2, 2023

pohly commented Oct 2, 2023

sttts commented Oct 4, 2023

k8s-ci-robot commented Oct 4, 2023

pohly commented Oct 4, 2023

pohly Sep 26, 2023 •

edited

alexzielenski commented Sep 19, 2023 •

edited