client-go: finish conversion to contextual logging

pohly · pohly · commit 4f211d5105ec · 2025-04-16T12:42:21.000+02:00
This changes the log output of kubectl, which affects some test cases which
check for GET results in that log output.
diff --git a/hack/golangci-hints.yaml b/hack/golangci-hints.yaml
@@ -148,11 +148,7 @@ linters-settings: # please keep this alphabetized
           # "contextual" implies "structured".
           contextual k8s.io/api/.*
           contextual k8s.io/apimachinery/.*
-          contextual k8s.io/client-go/metadata/.*
-          contextual k8s.io/client-go/rest/.*
-          contextual k8s.io/client-go/tools/cache/.*
-          contextual k8s.io/client-go/tools/events/.*
-          contextual k8s.io/client-go/tools/record/.*
+          contextual k8s.io/client-go/.*
           contextual k8s.io/component-helpers/.*
           contextual k8s.io/cri-api/.*
           contextual k8s.io/cri-client/.*
diff --git a/hack/golangci.yaml b/hack/golangci.yaml
@@ -214,11 +214,7 @@ linters-settings: # please keep this alphabetized
           # "contextual" implies "structured".
           contextual k8s.io/api/.*
           contextual k8s.io/apimachinery/.*
-          contextual k8s.io/client-go/metadata/.*
-          contextual k8s.io/client-go/rest/.*
-          contextual k8s.io/client-go/tools/cache/.*
-          contextual k8s.io/client-go/tools/events/.*
-          contextual k8s.io/client-go/tools/record/.*
+          contextual k8s.io/client-go/.*
           contextual k8s.io/component-helpers/.*
           contextual k8s.io/cri-api/.*
           contextual k8s.io/cri-client/.*
diff --git a/hack/logcheck.conf b/hack/logcheck.conf
@@ -26,11 +26,7 @@ structured k8s.io/apiserver/pkg/server/options/encryptionconfig/.*
 # "contextual" implies "structured".
 contextual k8s.io/api/.*
 contextual k8s.io/apimachinery/.*
-contextual k8s.io/client-go/metadata/.*
-contextual k8s.io/client-go/rest/.*
-contextual k8s.io/client-go/tools/cache/.*
-contextual k8s.io/client-go/tools/events/.*
-contextual k8s.io/client-go/tools/record/.*
+contextual k8s.io/client-go/.*
 contextual k8s.io/component-helpers/.*
 contextual k8s.io/cri-api/.*
 contextual k8s.io/cri-client/.*
diff --git a/staging/src/k8s.io/client-go/dynamic/simple.go b/staging/src/k8s.io/client-go/dynamic/simple.go
@@ -252,14 +252,14 @@ func (c *dynamicResourceClient) Get(ctx context.Context, name string, opts metav
 
 func (c *dynamicResourceClient) List(ctx context.Context, opts metav1.ListOptions) (*unstructured.UnstructuredList, error) {
 	if watchListOptions, hasWatchListOptionsPrepared, watchListOptionsErr := watchlist.PrepareWatchListOptionsFromListOptions(opts); watchListOptionsErr != nil {
-		klog.Warningf("Failed preparing watchlist options for %v, falling back to the standard LIST semantics, err = %v", c.resource, watchListOptionsErr)
+		klog.FromContext(ctx).Info("Warning: failed preparing watchlist options, falling back to the standard LIST semantics", "resource", c.resource, "err", watchListOptionsErr)
 	} else if hasWatchListOptionsPrepared {
 		result, err := c.watchList(ctx, watchListOptions)
 		if err == nil {
 			consistencydetector.CheckWatchListFromCacheDataConsistencyIfRequested(ctx, fmt.Sprintf("watchlist request for %v", c.resource), c.list, opts, result)
 			return result, nil
 		}
-		klog.Warningf("The watchlist request for %v ended with an error, falling back to the standard LIST semantics, err = %v", c.resource, err)
+		klog.FromContext(ctx).Info("Warning: the watchlist request ended with an error, falling back to the standard LIST semantics", "resource", c.resource, "err", err)
 	}
 	result, err := c.list(ctx, opts)
 	if err == nil {
diff --git a/staging/src/k8s.io/client-go/gentype/type.go b/staging/src/k8s.io/client-go/gentype/type.go
@@ -173,14 +173,14 @@ func (c *Client[T]) Get(ctx context.Context, name string, options metav1.GetOpti
 // List takes label and field selectors, and returns the list of resources that match those selectors.
 func (l *alsoLister[T, L]) List(ctx context.Context, opts metav1.ListOptions) (L, error) {
 	if watchListOptions, hasWatchListOptionsPrepared, watchListOptionsErr := watchlist.PrepareWatchListOptionsFromListOptions(opts); watchListOptionsErr != nil {
-		klog.Warningf("Failed preparing watchlist options for $.type|resource$, falling back to the standard LIST semantics, err = %v", watchListOptionsErr)
+		klog.FromContext(ctx).Info("Warning: failed preparing watchlist options, falling back to the standard LIST semantics", "resource", l.client.resource, "err", watchListOptionsErr)
 	} else if hasWatchListOptionsPrepared {
 		result, err := l.watchList(ctx, watchListOptions)
 		if err == nil {
 			consistencydetector.CheckWatchListFromCacheDataConsistencyIfRequested(ctx, "watchlist request for "+l.client.resource, l.list, opts, result)
 			return result, nil
 		}
-		klog.Warningf("The watchlist request for %s ended with an error, falling back to the standard LIST semantics, err = %v", l.client.resource, err)
+		klog.FromContext(ctx).Info("Warning: the watchlist request ended with an error, falling back to the standard LIST semantics", "resource", l.client.resource, "err", err)
 	}
 	result, err := l.list(ctx, opts)
 	if err == nil {
diff --git a/staging/src/k8s.io/client-go/tools/cache/reflector_data_consistency_detector.go b/staging/src/k8s.io/client-go/tools/cache/reflector_data_consistency_detector.go
@@ -33,6 +33,9 @@ import (
 //
 // Note that this function will panic when data inconsistency is detected.
 // This is intentional because we want to catch it in the CI.
+//
+// The identity string can be left empty if the logger in the context already
+// identifies what is being watched.
 func checkWatchListDataConsistencyIfRequested[T runtime.Object, U any](ctx context.Context, identity string, lastSyncedResourceVersion string, listFn consistencydetector.ListFunc[T], retrieveItemsFn consistencydetector.RetrieveItemsFunc[U]) {
 	if !consistencydetector.IsDataConsistencyDetectionForWatchListEnabled() {
 		return
diff --git a/staging/src/k8s.io/client-go/tools/events/event_broadcaster.go b/staging/src/k8s.io/client-go/tools/events/event_broadcaster.go
@@ -328,7 +328,7 @@ func (e *eventBroadcasterImpl) StartStructuredLogging(verbosity klog.Level) func
 // 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) {
-	return e.StartEventWatcher(
+	return e.startEventWatcher(logger,
 		func(obj runtime.Object) {
 			event, ok := obj.(*eventsv1.Event)
 			if !ok {
@@ -342,12 +342,16 @@ func (e *eventBroadcasterImpl) StartLogging(logger klog.Logger) (func(), error)
 // StartEventWatcher starts sending events received from this EventBroadcaster to the given event handler function.
 // The return value is used to stop recording
 func (e *eventBroadcasterImpl) StartEventWatcher(eventHandler func(event runtime.Object)) (func(), error) {
+	return e.startEventWatcher(klog.Background(), eventHandler)
+}
+
+func (e *eventBroadcasterImpl) startEventWatcher(logger klog.Logger, eventHandler func(event runtime.Object)) (func(), error) {
 	watcher, err := e.Watch()
 	if err != nil {
 		return nil, err
 	}
 	go func() {
-		defer utilruntime.HandleCrash()
+		defer utilruntime.HandleCrashWithLogger(logger)
 		for {
 			watchEvent, ok := <-watcher.ResultChan()
 			if !ok {
diff --git a/staging/src/k8s.io/client-go/tools/events/event_recorder.go b/staging/src/k8s.io/client-go/tools/events/event_recorder.go
@@ -83,7 +83,7 @@ func (recorder *recorderImpl) eventf(logger klog.Logger, regarding runtime.Objec
 	}
 	event := recorder.makeEvent(refRegarding, refRelated, timestamp, eventtype, reason, message, recorder.reportingController, recorder.reportingInstance, action)
 	go func() {
-		defer utilruntime.HandleCrash()
+		defer utilruntime.HandleCrashWithLogger(logger)
 		recorder.Action(watch.Added, event)
 	}()
 }
diff --git a/staging/src/k8s.io/client-go/tools/pager/pager.go b/staging/src/k8s.io/client-go/tools/pager/pager.go
@@ -219,7 +219,7 @@ func (p *ListPager) eachListChunkBuffered(ctx context.Context, options metav1.Li
 	chunkC := make(chan runtime.Object, p.PageBufferSize)
 	bgResultC := make(chan error, 1)
 	go func() {
-		defer utilruntime.HandleCrash()
+		defer utilruntime.HandleCrashWithContext(ctx)
 
 		var err error
 		defer func() {
diff --git a/staging/src/k8s.io/client-go/tools/record/event.go b/staging/src/k8s.io/client-go/tools/record/event.go
@@ -292,7 +292,7 @@ func (e *eventBroadcasterImpl) recordToSink(sink EventSink, event *v1.Event, eve
 	event = &eventCopy
 	result, err := eventCorrelator.EventCorrelate(event)
 	if err != nil {
-		utilruntime.HandleError(err)
+		utilruntime.HandleErrorWithContext(e.cancelationCtx, err, "Event correlation failed")
 	}
 	if result.Skip {
 		return
@@ -402,7 +402,7 @@ func (e *eventBroadcasterImpl) StartEventWatcher(eventHandler func(*v1.Event)) w
 		return watch.NewEmptyWatch()
 	}
 	go func() {
-		defer utilruntime.HandleCrash()
+		defer utilruntime.HandleCrashWithContext(e.cancelationCtx)
 		for {
 			select {
 			case <-e.cancelationCtx.Done():
diff --git a/staging/src/k8s.io/client-go/util/consistencydetector/data_consistency_detector.go b/staging/src/k8s.io/client-go/util/consistencydetector/data_consistency_detector.go
@@ -40,12 +40,19 @@ type ListFunc[T runtime.Object] func(ctx context.Context, options metav1.ListOpt
 // it is guarded by an environmental variable.
 // we cannot manipulate the environmental variable because
 // it will affect other tests in this package.
+//
+// The identity string can be left empty if the logger in the context already
+// identifies what is being watched.
 func CheckDataConsistency[T runtime.Object, U any](ctx context.Context, identity string, lastSyncedResourceVersion string, listFn ListFunc[T], listOptions metav1.ListOptions, retrieveItemsFn RetrieveItemsFunc[U]) {
+	logger := klog.FromContext(ctx)
+	if identity != "" {
+		logger = klog.LoggerWithName(logger, identity)
+	}
 	if !canFormAdditionalListCall(lastSyncedResourceVersion, listOptions) {
-		klog.V(4).Infof("data consistency check for %s is enabled but the parameters (RV, ListOptions) doesn't allow for creating a valid LIST request. Skipping the data consistency check.", identity)
+		logger.V(4).Info("Data consistency check is enabled but the parameters (RV, ListOptions) doesn't allow for creating a valid LIST request. Skipping the data consistency check.")
 		return
 	}
-	klog.Warningf("data consistency check for %s is enabled, this will result in an additional call to the API server.", identity)
+	logger.Info("Warning: data consistency check is enabled, this will result in an additional call to the API server.")
 
 	retrievedItems := toMetaObjectSliceOrDie(retrieveItemsFn())
 	listOptions = prepareListCallOptions(lastSyncedResourceVersion, listOptions, len(retrievedItems))
@@ -56,13 +63,13 @@ func CheckDataConsistency[T runtime.Object, U any](ctx context.Context, identity
 			// the consistency check will only be enabled in the CI
 			// and LIST calls in general will be retired by the client-go library
 			// if we fail simply log and retry
-			klog.Errorf("failed to list data from the server, retrying until stopCh is closed, err: %v", err)
+			logger.Info("Failed to list data from the server, retrying until context is canceled", "err", err)
 			return false, nil
 		}
 		return true, nil
 	})
 	if err != nil {
-		klog.Errorf("failed to list data from the server, the data consistency check for %s won't be performed, stopCh was closed, err: %v", identity, err)
+		logger.Error(err, "Failed to list data from the server, the data consistency check won't be performed, stopCh was closed")
 		return
 	}
 
@@ -76,9 +83,13 @@ func CheckDataConsistency[T runtime.Object, U any](ctx context.Context, identity
 	sort.Sort(byUID(retrievedItems))
 
 	if !cmp.Equal(listItems, retrievedItems) {
-		klog.Infof("previously received data for %s is different than received by the standard list api call against etcd, diff: %v", identity, cmp.Diff(listItems, retrievedItems))
-		msg := fmt.Sprintf("data inconsistency detected for %s, panicking!", identity)
-		panic(msg)
+		logger.Info("Previously received data is different than received by the standard list api call against etcd", "diff", cmp.Diff(listItems, retrievedItems))
+		if identity != "" {
+			msg := fmt.Sprintf("data inconsistency detected for %s, panicking!", identity)
+			panic(msg)
+		} else {
+			panic("data inconsistency detected, panicking!")
+		}
 	}
 }
 

Original file line number	Diff line number	Diff line change
`@@ -83,7 +83,7 @@ func (recorder *recorderImpl) eventf(logger klog.Logger, regarding runtime.Objec`
`83`	`83`	`}`
`84`	`84`	`event := recorder.makeEvent(refRegarding, refRelated, timestamp, eventtype, reason, message, recorder.reportingController, recorder.reportingInstance, action)`
`85`	`85`	`go func() {`
`86`		`- defer utilruntime.HandleCrash()`
	`86`	`+ defer utilruntime.HandleCrashWithLogger(logger)`
`87`	`87`	`recorder.Action(watch.Added, event)`
`88`	`88`	`}()`
`89`	`89`	`}`