enhance and fix log calls

Some of these changes are cosmetic (repeatedly calling klog.V instead of
reusing the result), others address real issues:

- Logging a message only above a certain verbosity threshold without
  recording that verbosity level (if klog.V().Enabled() { klog.Info... }):
  this matters when using a logging backend which records the verbosity
  level.

- Passing a format string with parameters to a logging function that
  doesn't do string formatting.

All of these locations where found by the enhanced logcheck tool from
kubernetes/klog#297.

In some cases it reports false positives, but those can be suppressed with
source code comments.

Kubernetes-commit: edffc700a43e610f641907290a5152ca593bad79

pkg/registry/generic/registry/storage_factory.go

@@ -49,8 +49,9 @@ func StorageWithCacher() generic.StorageDecorator {
 		if err != nil {
 			return s, d, err
 		}
-		if klog.V(5).Enabled() {
-			klog.V(5).InfoS("Storage caching is enabled", objectTypeToArgs(newFunc())...)
+		if klogV := klog.V(5); klogV.Enabled() {
+			//nolint:logcheck // It complains about the key/value pairs because it cannot check them.
+			klogV.InfoS("Storage caching is enabled", objectTypeToArgs(newFunc())...)
 		}
 
 		cacherConfig := cacherstorage.Config{

pkg/server/filters/priority-and-fairness.go

@@ -125,6 +125,10 @@ func WithPriorityAndFairness(
 			workEstimate := workEstimator(r, classification.FlowSchemaName, classification.PriorityLevelName)
 
 			fcmetrics.ObserveWorkEstimatedSeats(classification.PriorityLevelName, classification.FlowSchemaName, workEstimate.MaxSeats())
+			// nolint:logcheck // Not using the result of klog.V
+			// inside the if branch is okay, we just use it to
+			// determine whether the additional information should
+			// be added.
 			if klog.V(4).Enabled() {
 				httplog.AddKeyValue(ctx, "apf_iseats", workEstimate.InitialSeats)
 				httplog.AddKeyValue(ctx, "apf_fseats", workEstimate.FinalSeats)

pkg/storage/etcd3/logger.go

@@ -32,19 +32,19 @@ type klogWrapper struct{}
 const klogWrapperDepth = 4
 
 func (klogWrapper) Info(args ...interface{}) {
-	if klog.V(5).Enabled() {
-		klog.V(5).InfoSDepth(klogWrapperDepth, fmt.Sprint(args...))
+	if klogV := klog.V(5); klogV.Enabled() {
+		klogV.InfoSDepth(klogWrapperDepth, fmt.Sprint(args...))
 	}
 }
 
 func (klogWrapper) Infoln(args ...interface{}) {
-	if klog.V(5).Enabled() {
-		klog.V(5).InfoSDepth(klogWrapperDepth, fmt.Sprintln(args...))
+	if klogV := klog.V(5); klogV.Enabled() {
+		klogV.InfoSDepth(klogWrapperDepth, fmt.Sprintln(args...))
 	}
 }
 
 func (klogWrapper) Infof(format string, args ...interface{}) {
-	if klog.V(5).Enabled() {
+	if klogV := klog.V(5); klogV.Enabled() {
 		klog.V(5).InfoSDepth(klogWrapperDepth, fmt.Sprintf(format, args...))
 	}
 }

pkg/util/flowcontrol/apf_controller.go

@@ -434,8 +434,8 @@ func (cfgCtlr *configController) digestConfigObjects(newPLs []*flowcontrol.Prior
 
 		// if we are going to issue an update, be sure we track every name we update so we know if we update it too often.
 		currResult.updatedItems.Insert(fsu.flowSchema.Name)
-		if klog.V(4).Enabled() {
-			klog.V(4).Infof("%s writing Condition %s to FlowSchema %s, which had ResourceVersion=%s, because its previous value was %s, diff: %s",
+		if klogV := klog.V(4); klogV.Enabled() {
+			klogV.Infof("%s writing Condition %s to FlowSchema %s, which had ResourceVersion=%s, because its previous value was %s, diff: %s",
 				cfgCtlr.name, fsu.condition, fsu.flowSchema.Name, fsu.flowSchema.ResourceVersion, fcfmt.Fmt(fsu.oldValue), cmp.Diff(fsu.oldValue, fsu.condition))
 		}
 		fsIfc := cfgCtlr.flowcontrolClient.FlowSchemas()

pkg/util/flowcontrol/fairqueuing/queueset/queueset.go

@@ -573,9 +573,9 @@ func (qs *queueSet) shuffleShardLocked(hashValue uint64, descr1, descr2 interfac
 			bestQueueIdx = queueIdx
 		}
 	}
-	if klog.V(6).Enabled() {
+	if klogV := klog.V(6); klogV.Enabled() {
 		chosenQueue := qs.queues[bestQueueIdx]
-		klog.V(6).Infof("QS(%s) at t=%s R=%v: For request %#+v %#+v chose queue %d, with sum: %#v & %d seats in use & nextDispatchR=%v", qs.qCfg.Name, qs.clock.Now().Format(nsTimeFmt), qs.currentR, descr1, descr2, bestQueueIdx, chosenQueue.requests.QueueSum(), chosenQueue.seatsInUse, chosenQueue.nextDispatchR)
+		klogV.Infof("QS(%s) at t=%s R=%v: For request %#+v %#+v chose queue %d, with sum: %#v & %d seats in use & nextDispatchR=%v", qs.qCfg.Name, qs.clock.Now().Format(nsTimeFmt), qs.currentR, descr1, descr2, bestQueueIdx, chosenQueue.requests.QueueSum(), chosenQueue.seatsInUse, chosenQueue.nextDispatchR)
 	}
 	return bestQueueIdx
 }