convert k8s.io/kubernetes/pkg/proxy to contextual logging, part 1

Signed-off-by: Ziqi Zhao <zhaoziqi9146@gmail.com>
2025-11-01 18:58:18 +00:00 · 2024-01-26 13:10:53 +08:00
parent c1924df0a8
commit be4535bd34
19 changed files with 542 additions and 420 deletions
--- a/pkg/proxy/iptables/proxier.go
+++ b/pkg/proxy/iptables/proxier.go
@@ -25,6 +25,7 @@ package iptables

 import (
 	"bytes"
+	"context"
 	"crypto/sha256"
 	"encoding/base32"
 	"fmt"
@@ -97,6 +98,7 @@ const sysctlNFConntrackTCPBeLiberal = "net/netfilter/nf_conntrack_tcp_be_liberal

 // NewDualStackProxier creates a MetaProxier instance, with IPv4 and IPv6 proxies.
 func NewDualStackProxier(
+	ctx context.Context,
 	ipt [2]utiliptables.Interface,
 	sysctl utilsysctl.Interface,
 	exec utilexec.Interface,
@@ -114,14 +116,14 @@ func NewDualStackProxier(
 	initOnly bool,
 ) (proxy.Provider, error) {
 	// Create an ipv4 instance of the single-stack proxier
-	ipv4Proxier, err := NewProxier(v1.IPv4Protocol, ipt[0], sysctl,
+	ipv4Proxier, err := NewProxier(ctx, v1.IPv4Protocol, ipt[0], sysctl,
 		exec, syncPeriod, minSyncPeriod, masqueradeAll, localhostNodePorts, masqueradeBit, localDetectors[0], hostname,
 		nodeIPs[v1.IPv4Protocol], recorder, healthzServer, nodePortAddresses, initOnly)
 	if err != nil {
 		return nil, fmt.Errorf("unable to create ipv4 proxier: %v", err)
 	}

-	ipv6Proxier, err := NewProxier(v1.IPv6Protocol, ipt[1], sysctl,
+	ipv6Proxier, err := NewProxier(ctx, v1.IPv6Protocol, ipt[1], sysctl,
 		exec, syncPeriod, minSyncPeriod, masqueradeAll, false, masqueradeBit, localDetectors[1], hostname,
 		nodeIPs[v1.IPv6Protocol], recorder, healthzServer, nodePortAddresses, initOnly)
 	if err != nil {
@@ -205,6 +207,8 @@ type Proxier struct {
 	// networkInterfacer defines an interface for several net library functions.
 	// Inject for test purpose.
 	networkInterfacer proxyutil.NetworkInterfacer
+
+	logger klog.Logger
 }

 // Proxier implements proxy.Provider
@@ -215,7 +219,8 @@ var _ proxy.Provider = &Proxier{}
 // An error will be returned if iptables fails to update or acquire the initial lock.
 // Once a proxier is created, it will keep iptables up to date in the background and
 // will not terminate if a particular iptables call fails.
-func NewProxier(ipFamily v1.IPFamily,
+func NewProxier(ctx context.Context,
+	ipFamily v1.IPFamily,
 	ipt utiliptables.Interface,
 	sysctl utilsysctl.Interface,
 	exec utilexec.Interface,
@@ -232,6 +237,7 @@ func NewProxier(ipFamily v1.IPFamily,
 	nodePortAddressStrings []string,
 	initOnly bool,
 ) (*Proxier, error) {
+	logger := klog.LoggerWithValues(klog.FromContext(ctx), "ipFamily", ipFamily)
 	nodePortAddresses := proxyutil.NewNodePortAddresses(ipFamily, nodePortAddressStrings)

 	if !nodePortAddresses.ContainsIPv4Loopback() {
@@ -240,7 +246,7 @@ func NewProxier(ipFamily v1.IPFamily,
 	if localhostNodePorts {
 		// Set the route_localnet sysctl we need for exposing NodePorts on loopback addresses
 		// Refer to https://issues.k8s.io/90259
-		klog.InfoS("Setting route_localnet=1 to allow node-ports on localhost; to change this either disable iptables.localhostNodePorts (--iptables-localhost-nodeports) or set nodePortAddresses (--nodeport-addresses) to filter loopback addresses")
+		logger.Info("Setting route_localnet=1 to allow node-ports on localhost; to change this either disable iptables.localhostNodePorts (--iptables-localhost-nodeports) or set nodePortAddresses (--nodeport-addresses) to filter loopback addresses")
 		if err := proxyutil.EnsureSysctl(sysctl, sysctlRouteLocalnet, 1); err != nil {
 			return nil, err
 		}
@@ -252,18 +258,18 @@ func NewProxier(ipFamily v1.IPFamily,
 	conntrackTCPLiberal := false
 	if val, err := sysctl.GetSysctl(sysctlNFConntrackTCPBeLiberal); err == nil && val != 0 {
 		conntrackTCPLiberal = true
-		klog.InfoS("nf_conntrack_tcp_be_liberal set, not installing DROP rules for INVALID packets")
+		logger.Info("nf_conntrack_tcp_be_liberal set, not installing DROP rules for INVALID packets")
 	}

 	if initOnly {
-		klog.InfoS("System initialized and --init-only specified")
+		logger.Info("System initialized and --init-only specified")
 		return nil, nil
 	}

 	// Generate the masquerade mark to use for SNAT rules.
 	masqueradeValue := 1 << uint(masqueradeBit)
 	masqueradeMark := fmt.Sprintf("%#08x", masqueradeValue)
-	klog.V(2).InfoS("Using iptables mark for masquerade", "ipFamily", ipt.Protocol(), "mark", masqueradeMark)
+	logger.V(2).Info("Using iptables mark for masquerade", "mark", masqueradeMark)

 	serviceHealthServer := healthcheck.NewServiceHealthServer(hostname, recorder, nodePortAddresses, healthzServer)

@@ -296,10 +302,11 @@ func NewProxier(ipFamily v1.IPFamily,
 		nodePortAddresses:        nodePortAddresses,
 		networkInterfacer:        proxyutil.RealNetwork{},
 		conntrackTCPLiberal:      conntrackTCPLiberal,
+		logger:                   logger,
 	}

 	burstSyncs := 2
-	klog.V(2).InfoS("Iptables sync params", "ipFamily", ipt.Protocol(), "minSyncPeriod", minSyncPeriod, "syncPeriod", syncPeriod, "burstSyncs", burstSyncs)
+	logger.V(2).Info("Iptables sync params", "minSyncPeriod", minSyncPeriod, "syncPeriod", syncPeriod, "burstSyncs", burstSyncs)
 	// We pass syncPeriod to ipt.Monitor, which will call us only if it needs to.
 	// We need to pass *some* maxInterval to NewBoundedFrequencyRunner anyway though.
 	// time.Hour is arbitrary.
@@ -309,9 +316,9 @@ func NewProxier(ipFamily v1.IPFamily,
 		proxier.forceSyncProxyRules, syncPeriod, wait.NeverStop)

 	if ipt.HasRandomFully() {
-		klog.V(2).InfoS("Iptables supports --random-fully", "ipFamily", ipt.Protocol())
+		logger.V(2).Info("Iptables supports --random-fully")
 	} else {
-		klog.V(2).InfoS("Iptables does not support --random-fully", "ipFamily", ipt.Protocol())
+		logger.V(2).Info("Iptables does not support --random-fully")
 	}

 	return proxier, nil
@@ -396,7 +403,8 @@ var iptablesCleanupOnlyChains = []iptablesJumpChain{}

 // CleanupLeftovers removes all iptables rules and chains created by the Proxier
 // It returns true if an error was encountered. Errors are logged.
-func CleanupLeftovers(ipt utiliptables.Interface) (encounteredError bool) {
+func CleanupLeftovers(ctx context.Context, ipt utiliptables.Interface) (encounteredError bool) {
+	logger := klog.FromContext(ctx)
 	// Unlink our chains
 	for _, jump := range append(iptablesJumpChains, iptablesCleanupOnlyChains...) {
 		args := append(jump.extraArgs,
@@ -405,7 +413,7 @@ func CleanupLeftovers(ipt utiliptables.Interface) (encounteredError bool) {
 		)
 		if err := ipt.DeleteRule(jump.table, jump.srcChain, args...); err != nil {
 			if !utiliptables.IsNotFoundError(err) {
-				klog.ErrorS(err, "Error removing pure-iptables proxy rule")
+				logger.Error(err, "Error removing pure-iptables proxy rule")
 				encounteredError = true
 			}
 		}
@@ -414,7 +422,7 @@ func CleanupLeftovers(ipt utiliptables.Interface) (encounteredError bool) {
 	// Flush and remove all of our "-t nat" chains.
 	iptablesData := bytes.NewBuffer(nil)
 	if err := ipt.SaveInto(utiliptables.TableNAT, iptablesData); err != nil {
-		klog.ErrorS(err, "Failed to execute iptables-save", "table", utiliptables.TableNAT)
+		logger.Error(err, "Failed to execute iptables-save", "table", utiliptables.TableNAT)
 		encounteredError = true
 	} else {
 		existingNATChains := utiliptables.GetChainsFromTable(iptablesData.Bytes())
@@ -442,7 +450,7 @@ func CleanupLeftovers(ipt utiliptables.Interface) (encounteredError bool) {
 		// Write it.
 		err = ipt.Restore(utiliptables.TableNAT, natLines, utiliptables.NoFlushTables, utiliptables.RestoreCounters)
 		if err != nil {
-			klog.ErrorS(err, "Failed to execute iptables-restore", "table", utiliptables.TableNAT)
+			logger.Error(err, "Failed to execute iptables-restore", "table", utiliptables.TableNAT)
 			metrics.IptablesRestoreFailuresTotal.Inc()
 			encounteredError = true
 		}
@@ -451,7 +459,7 @@ func CleanupLeftovers(ipt utiliptables.Interface) (encounteredError bool) {
 	// Flush and remove all of our "-t filter" chains.
 	iptablesData.Reset()
 	if err := ipt.SaveInto(utiliptables.TableFilter, iptablesData); err != nil {
-		klog.ErrorS(err, "Failed to execute iptables-save", "table", utiliptables.TableFilter)
+		logger.Error(err, "Failed to execute iptables-save", "table", utiliptables.TableFilter)
 		encounteredError = true
 	} else {
 		existingFilterChains := utiliptables.GetChainsFromTable(iptablesData.Bytes())
@@ -469,7 +477,7 @@ func CleanupLeftovers(ipt utiliptables.Interface) (encounteredError bool) {
 		filterLines := append(filterChains.Bytes(), filterRules.Bytes()...)
 		// Write it.
 		if err := ipt.Restore(utiliptables.TableFilter, filterLines, utiliptables.NoFlushTables, utiliptables.RestoreCounters); err != nil {
-			klog.ErrorS(err, "Failed to execute iptables-restore", "table", utiliptables.TableFilter)
+			logger.Error(err, "Failed to execute iptables-restore", "table", utiliptables.TableFilter)
 			metrics.IptablesRestoreFailuresTotal.Inc()
 			encounteredError = true
 		}
@@ -605,7 +613,7 @@ func (proxier *Proxier) OnEndpointSlicesSynced() {
 // is observed.
 func (proxier *Proxier) OnNodeAdd(node *v1.Node) {
 	if node.Name != proxier.hostname {
-		klog.ErrorS(nil, "Received a watch event for a node that doesn't match the current node",
+		proxier.logger.Error(nil, "Received a watch event for a node that doesn't match the current node",
 			"eventNode", node.Name, "currentNode", proxier.hostname)
 		return
 	}
@@ -621,7 +629,7 @@ func (proxier *Proxier) OnNodeAdd(node *v1.Node) {
 	}
 	proxier.needFullSync = true
 	proxier.mu.Unlock()
-	klog.V(4).InfoS("Updated proxier node labels", "labels", node.Labels)
+	proxier.logger.V(4).Info("Updated proxier node labels", "labels", node.Labels)

 	proxier.Sync()
 }
@@ -630,7 +638,7 @@ func (proxier *Proxier) OnNodeAdd(node *v1.Node) {
 // node object is observed.
 func (proxier *Proxier) OnNodeUpdate(oldNode, node *v1.Node) {
 	if node.Name != proxier.hostname {
-		klog.ErrorS(nil, "Received a watch event for a node that doesn't match the current node",
+		proxier.logger.Error(nil, "Received a watch event for a node that doesn't match the current node",
 			"eventNode", node.Name, "currentNode", proxier.hostname)
 		return
 	}
@@ -646,7 +654,7 @@ func (proxier *Proxier) OnNodeUpdate(oldNode, node *v1.Node) {
 	}
 	proxier.needFullSync = true
 	proxier.mu.Unlock()
-	klog.V(4).InfoS("Updated proxier node labels", "labels", node.Labels)
+	proxier.logger.V(4).Info("Updated proxier node labels", "labels", node.Labels)

 	proxier.Sync()
 }
@@ -655,7 +663,7 @@ func (proxier *Proxier) OnNodeUpdate(oldNode, node *v1.Node) {
 // object is observed.
 func (proxier *Proxier) OnNodeDelete(node *v1.Node) {
 	if node.Name != proxier.hostname {
-		klog.ErrorS(nil, "Received a watch event for a node that doesn't match the current node",
+		proxier.logger.Error(nil, "Received a watch event for a node that doesn't match the current node",
 			"eventNode", node.Name, "currentNode", proxier.hostname)
 		return
 	}
@@ -779,7 +787,7 @@ func (proxier *Proxier) syncProxyRules() {

 	// don't sync rules till we've received services and endpoints
 	if !proxier.isInitialized() {
-		klog.V(2).InfoS("Not syncing iptables until Services and Endpoints have been received from master")
+		proxier.logger.V(2).Info("Not syncing iptables until Services and Endpoints have been received from master")
 		return
 	}

@@ -796,18 +804,18 @@ func (proxier *Proxier) syncProxyRules() {
 		} else {
 			metrics.SyncFullProxyRulesLatency.Observe(metrics.SinceInSeconds(start))
 		}
-		klog.V(2).InfoS("SyncProxyRules complete", "elapsed", time.Since(start))
+		proxier.logger.V(2).Info("SyncProxyRules complete", "elapsed", time.Since(start))
 	}()

 	serviceUpdateResult := proxier.svcPortMap.Update(proxier.serviceChanges)
 	endpointUpdateResult := proxier.endpointsMap.Update(proxier.endpointsChanges)

-	klog.V(2).InfoS("Syncing iptables rules")
+	proxier.logger.V(2).Info("Syncing iptables rules")

 	success := false
 	defer func() {
 		if !success {
-			klog.InfoS("Sync failed", "retryingTime", proxier.syncPeriod)
+			proxier.logger.Info("Sync failed", "retryingTime", proxier.syncPeriod)
 			proxier.syncRunner.RetryAfter(proxier.syncPeriod)
 			if tryPartialSync {
 				metrics.IptablesPartialRestoreFailuresTotal.Inc()
@@ -833,7 +841,7 @@ func (proxier *Proxier) syncProxyRules() {
 		// (which will be very slow on hosts with lots of iptables rules).
 		for _, jump := range append(iptablesJumpChains, iptablesKubeletJumpChains...) {
 			if _, err := proxier.iptables.EnsureChain(jump.table, jump.dstChain); err != nil {
-				klog.ErrorS(err, "Failed to ensure chain exists", "table", jump.table, "chain", jump.dstChain)
+				proxier.logger.Error(err, "Failed to ensure chain exists", "table", jump.table, "chain", jump.dstChain)
 				return
 			}
 			args := jump.extraArgs
@@ -842,7 +850,7 @@ func (proxier *Proxier) syncProxyRules() {
 			}
 			args = append(args, "-j", string(jump.dstChain))
 			if _, err := proxier.iptables.EnsureRule(utiliptables.Prepend, jump.table, jump.srcChain, args...); err != nil {
-				klog.ErrorS(err, "Failed to ensure chain jumps", "table", jump.table, "srcChain", jump.srcChain, "dstChain", jump.dstChain)
+				proxier.logger.Error(err, "Failed to ensure chain jumps", "table", jump.table, "srcChain", jump.srcChain, "dstChain", jump.dstChain)
 				return
 			}
 		}
@@ -952,7 +960,7 @@ func (proxier *Proxier) syncProxyRules() {
 	for svcName, svc := range proxier.svcPortMap {
 		svcInfo, ok := svc.(*servicePortInfo)
 		if !ok {
-			klog.ErrorS(nil, "Failed to cast serviceInfo", "serviceName", svcName)
+			proxier.logger.Error(nil, "Failed to cast serviceInfo", "serviceName", svcName)
 			continue
 		}
 		protocol := strings.ToLower(string(svcInfo.Protocol()))
@@ -1345,7 +1353,7 @@ func (proxier *Proxier) syncProxyRules() {
 		for _, ep := range allLocallyReachableEndpoints {
 			epInfo, ok := ep.(*endpointInfo)
 			if !ok {
-				klog.ErrorS(nil, "Failed to cast endpointInfo", "endpointInfo", ep)
+				proxier.logger.Error(nil, "Failed to cast endpointInfo", "endpointInfo", ep)
 				continue
 			}

@@ -1396,7 +1404,7 @@ func (proxier *Proxier) syncProxyRules() {
 			}
 			proxier.lastIPTablesCleanup = time.Now()
 		} else {
-			klog.ErrorS(err, "Failed to execute iptables-save: stale chains will not be deleted")
+			proxier.logger.Error(err, "Failed to execute iptables-save: stale chains will not be deleted")
 		}
 	}

@@ -1420,15 +1428,15 @@ func (proxier *Proxier) syncProxyRules() {
 	} else {
 		nodeIPs, err := proxier.nodePortAddresses.GetNodeIPs(proxier.networkInterfacer)
 		if err != nil {
-			klog.ErrorS(err, "Failed to get node ip address matching nodeport cidrs, services with nodeport may not work as intended", "CIDRs", proxier.nodePortAddresses)
+			proxier.logger.Error(err, "Failed to get node ip address matching nodeport cidrs, services with nodeport may not work as intended", "CIDRs", proxier.nodePortAddresses)
 		}
 		for _, ip := range nodeIPs {
 			if ip.IsLoopback() {
 				if isIPv6 {
-					klog.ErrorS(nil, "--nodeport-addresses includes localhost but localhost NodePorts are not supported on IPv6", "address", ip.String())
+					proxier.logger.Error(nil, "--nodeport-addresses includes localhost but localhost NodePorts are not supported on IPv6", "address", ip.String())
 					continue
 				} else if !proxier.localhostNodePorts {
-					klog.ErrorS(nil, "--nodeport-addresses includes localhost but --iptables-localhost-nodeports=false was passed", "address", ip.String())
+					proxier.logger.Error(nil, "--nodeport-addresses includes localhost but --iptables-localhost-nodeports=false was passed", "address", ip.String())
 					continue
 				}
 			}
@@ -1491,7 +1499,7 @@ func (proxier *Proxier) syncProxyRules() {
 	proxier.iptablesData.Write(proxier.natRules.Bytes())
 	proxier.iptablesData.WriteString("COMMIT\n")

-	klog.V(2).InfoS("Reloading service iptables data",
+	proxier.logger.V(2).Info("Reloading service iptables data",
 		"numServices", len(proxier.svcPortMap),
 		"numEndpoints", totalEndpoints,
 		"numFilterChains", proxier.filterChains.Lines(),
@@ -1499,16 +1507,16 @@ func (proxier *Proxier) syncProxyRules() {
 		"numNATChains", proxier.natChains.Lines(),
 		"numNATRules", proxier.natRules.Lines(),
 	)
-	klog.V(9).InfoS("Restoring iptables", "rules", proxier.iptablesData.Bytes())
+	proxier.logger.V(9).Info("Restoring iptables", "rules", proxier.iptablesData.Bytes())

 	// NOTE: NoFlushTables is used so we don't flush non-kubernetes chains in the table
 	err := proxier.iptables.RestoreAll(proxier.iptablesData.Bytes(), utiliptables.NoFlushTables, utiliptables.RestoreCounters)
 	if err != nil {
 		if pErr, ok := err.(utiliptables.ParseError); ok {
 			lines := utiliptables.ExtractLines(proxier.iptablesData.Bytes(), pErr.Line(), 3)
-			klog.ErrorS(pErr, "Failed to execute iptables-restore", "rules", lines)
+			proxier.logger.Error(pErr, "Failed to execute iptables-restore", "rules", lines)
 		} else {
-			klog.ErrorS(err, "Failed to execute iptables-restore")
+			proxier.logger.Error(err, "Failed to execute iptables-restore")
 		}
 		metrics.IptablesRestoreFailuresTotal.Inc()
 		return
@@ -1520,7 +1528,7 @@ func (proxier *Proxier) syncProxyRules() {
 		for _, lastChangeTriggerTime := range lastChangeTriggerTimes {
 			latency := metrics.SinceInSeconds(lastChangeTriggerTime)
 			metrics.NetworkProgrammingLatency.Observe(latency)
-			klog.V(4).InfoS("Network programming", "endpoint", klog.KRef(name.Namespace, name.Name), "elapsed", latency)
+			proxier.logger.V(4).Info("Network programming", "endpoint", klog.KRef(name.Namespace, name.Name), "elapsed", latency)
 		}
 	}

@@ -1535,10 +1543,10 @@ func (proxier *Proxier) syncProxyRules() {
 	// not "OnlyLocal", but the services list will not, and the serviceHealthServer
 	// will just drop those endpoints.
 	if err := proxier.serviceHealthServer.SyncServices(proxier.svcPortMap.HealthCheckNodePorts()); err != nil {
-		klog.ErrorS(err, "Error syncing healthcheck services")
+		proxier.logger.Error(err, "Error syncing healthcheck services")
 	}
 	if err := proxier.serviceHealthServer.SyncEndpoints(proxier.endpointsMap.LocalReadyEndpoints()); err != nil {
-		klog.ErrorS(err, "Error syncing healthcheck endpoints")
+		proxier.logger.Error(err, "Error syncing healthcheck endpoints")
 	}

 	// Finish housekeeping, clear stale conntrack entries for UDP Services
--- a/pkg/proxy/iptables/proxier_test.go
+++ b/pkg/proxy/iptables/proxier_test.go
@@ -46,6 +46,7 @@ import (
 	"k8s.io/component-base/metrics/legacyregistry"
 	"k8s.io/component-base/metrics/testutil"
 	"k8s.io/klog/v2"
+	klogtesting "k8s.io/klog/v2/ktesting"
 	"k8s.io/kubernetes/pkg/features"
 	"k8s.io/kubernetes/pkg/proxy"
 	"k8s.io/kubernetes/pkg/proxy/conntrack"
@@ -387,17 +388,17 @@ func TestParseIPTablesData(t *testing.T) {
 	}
 }

-func countRules(tableName utiliptables.Table, ruleData string) int {
+func countRules(logger klog.Logger, tableName utiliptables.Table, ruleData string) int {
 	dump, err := iptablestest.ParseIPTablesDump(ruleData)
 	if err != nil {
-		klog.ErrorS(err, "error parsing iptables rules")
+		logger.Error(err, "error parsing iptables rules")
 		return -1
 	}

 	rules := 0
 	table, err := dump.GetTable(tableName)
 	if err != nil {
-		klog.ErrorS(err, "can't find table", "table", tableName)
+		logger.Error(err, "can't find table", "table", tableName)
 		return -1
 	}

@@ -407,19 +408,19 @@ func countRules(tableName utiliptables.Table, ruleData string) int {
 	return rules
 }

-func countRulesFromMetric(tableName utiliptables.Table) int {
+func countRulesFromMetric(logger klog.Logger, tableName utiliptables.Table) int {
 	numRulesFloat, err := testutil.GetGaugeMetricValue(metrics.IptablesRulesTotal.WithLabelValues(string(tableName)))
 	if err != nil {
-		klog.ErrorS(err, "metrics are not registered?")
+		logger.Error(err, "metrics are not registered?")
 		return -1
 	}
 	return int(numRulesFloat)
 }

-func countRulesFromLastSyncMetric(tableName utiliptables.Table) int {
+func countRulesFromLastSyncMetric(logger klog.Logger, tableName utiliptables.Table) int {
 	numRulesFloat, err := testutil.GetGaugeMetricValue(metrics.IptablesRulesLastSync.WithLabelValues(string(tableName)))
 	if err != nil {
-		klog.ErrorS(err, "metrics are not registered?")
+		logger.Error(err, "metrics are not registered?")
 		return -1
 	}
 	return int(numRulesFloat)
@@ -1540,6 +1541,7 @@ func TestTracePacket(t *testing.T) {
 // TestOverallIPTablesRules creates a variety of services and verifies that the generated
 // rules are exactly as expected.
 func TestOverallIPTablesRules(t *testing.T) {
+	logger, _ := klogtesting.NewTestContext(t)
 	ipt := iptablestest.NewFake()
 	fp := NewFakeProxier(ipt)
 	metrics.RegisterMetrics()
@@ -1799,8 +1801,8 @@ func TestOverallIPTablesRules(t *testing.T) {

 	assertIPTablesRulesEqual(t, getLine(), true, expected, fp.iptablesData.String())

-	nNatRules := countRulesFromMetric(utiliptables.TableNAT)
-	expectedNatRules := countRules(utiliptables.TableNAT, fp.iptablesData.String())
+	nNatRules := countRulesFromMetric(logger, utiliptables.TableNAT)
+	expectedNatRules := countRules(logger, utiliptables.TableNAT, fp.iptablesData.String())

 	if nNatRules != expectedNatRules {
 		t.Fatalf("Wrong number of nat rules: expected %d received %d", expectedNatRules, nNatRules)
@@ -4142,6 +4144,7 @@ func TestHealthCheckNodePortWhenTerminating(t *testing.T) {
 }

 func TestProxierMetricsIptablesTotalRules(t *testing.T) {
+	logger, _ := klogtesting.NewTestContext(t)
 	ipt := iptablestest.NewFake()
 	fp := NewFakeProxier(ipt)

@@ -4170,15 +4173,15 @@ func TestProxierMetricsIptablesTotalRules(t *testing.T) {
 	fp.syncProxyRules()
 	iptablesData := fp.iptablesData.String()

-	nFilterRules := countRulesFromMetric(utiliptables.TableFilter)
-	expectedFilterRules := countRules(utiliptables.TableFilter, iptablesData)
+	nFilterRules := countRulesFromMetric(logger, utiliptables.TableFilter)
+	expectedFilterRules := countRules(logger, utiliptables.TableFilter, iptablesData)

 	if nFilterRules != expectedFilterRules {
 		t.Fatalf("Wrong number of filter rule: expected %d got %d\n%s", expectedFilterRules, nFilterRules, iptablesData)
 	}

-	nNatRules := countRulesFromMetric(utiliptables.TableNAT)
-	expectedNatRules := countRules(utiliptables.TableNAT, iptablesData)
+	nNatRules := countRulesFromMetric(logger, utiliptables.TableNAT)
+	expectedNatRules := countRules(logger, utiliptables.TableNAT, iptablesData)

 	if nNatRules != expectedNatRules {
 		t.Fatalf("Wrong number of nat rules: expected %d got %d\n%s", expectedNatRules, nNatRules, iptablesData)
@@ -4203,15 +4206,15 @@ func TestProxierMetricsIptablesTotalRules(t *testing.T) {
 	fp.syncProxyRules()
 	iptablesData = fp.iptablesData.String()

-	nFilterRules = countRulesFromMetric(utiliptables.TableFilter)
-	expectedFilterRules = countRules(utiliptables.TableFilter, iptablesData)
+	nFilterRules = countRulesFromMetric(logger, utiliptables.TableFilter)
+	expectedFilterRules = countRules(logger, utiliptables.TableFilter, iptablesData)

 	if nFilterRules != expectedFilterRules {
 		t.Fatalf("Wrong number of filter rule: expected %d got %d\n%s", expectedFilterRules, nFilterRules, iptablesData)
 	}

-	nNatRules = countRulesFromMetric(utiliptables.TableNAT)
-	expectedNatRules = countRules(utiliptables.TableNAT, iptablesData)
+	nNatRules = countRulesFromMetric(logger, utiliptables.TableNAT)
+	expectedNatRules = countRules(logger, utiliptables.TableNAT, iptablesData)

 	if nNatRules != expectedNatRules {
 		t.Fatalf("Wrong number of nat rules: expected %d got %d\n%s", expectedNatRules, nNatRules, iptablesData)
@@ -5822,6 +5825,7 @@ func TestSyncProxyRulesLargeClusterMode(t *testing.T) {

 // Test calling syncProxyRules() multiple times with various changes
 func TestSyncProxyRulesRepeated(t *testing.T) {
+	logger, _ := klogtesting.NewTestContext(t)
 	ipt := iptablestest.NewFake()
 	fp := NewFakeProxier(ipt)
 	metrics.RegisterMetrics()
@@ -5920,14 +5924,14 @@ func TestSyncProxyRulesRepeated(t *testing.T) {
 		`)
 	assertIPTablesRulesEqual(t, getLine(), true, expected, fp.iptablesData.String())

-	rulesSynced := countRules(utiliptables.TableNAT, expected)
-	rulesSyncedMetric := countRulesFromLastSyncMetric(utiliptables.TableNAT)
+	rulesSynced := countRules(logger, utiliptables.TableNAT, expected)
+	rulesSyncedMetric := countRulesFromLastSyncMetric(logger, utiliptables.TableNAT)
 	if rulesSyncedMetric != rulesSynced {
 		t.Errorf("metric shows %d rules synced but iptables data shows %d", rulesSyncedMetric, rulesSynced)
 	}

 	rulesTotal := rulesSynced
-	rulesTotalMetric := countRulesFromMetric(utiliptables.TableNAT)
+	rulesTotalMetric := countRulesFromMetric(logger, utiliptables.TableNAT)
 	if rulesTotalMetric != rulesTotal {
 		t.Errorf("metric shows %d rules total but expected %d", rulesTotalMetric, rulesTotal)
 	}
@@ -5998,8 +6002,8 @@ func TestSyncProxyRulesRepeated(t *testing.T) {
 		`)
 	assertIPTablesRulesEqual(t, getLine(), false, expected, fp.iptablesData.String())

-	rulesSynced = countRules(utiliptables.TableNAT, expected)
-	rulesSyncedMetric = countRulesFromLastSyncMetric(utiliptables.TableNAT)
+	rulesSynced = countRules(logger, utiliptables.TableNAT, expected)
+	rulesSyncedMetric = countRulesFromLastSyncMetric(logger, utiliptables.TableNAT)
 	if rulesSyncedMetric != rulesSynced {
 		t.Errorf("metric shows %d rules synced but iptables data shows %d", rulesSyncedMetric, rulesSynced)
 	}
@@ -6007,7 +6011,7 @@ func TestSyncProxyRulesRepeated(t *testing.T) {
 	// We added 1 KUBE-SERVICES rule, 2 KUBE-SVC-X27LE4BHSL4DOUIK rules, and 2
 	// KUBE-SEP-BSWRHOQ77KEXZLNL rules.
 	rulesTotal += 5
-	rulesTotalMetric = countRulesFromMetric(utiliptables.TableNAT)
+	rulesTotalMetric = countRulesFromMetric(logger, utiliptables.TableNAT)
 	if rulesTotalMetric != rulesTotal {
 		t.Errorf("metric shows %d rules total but expected %d", rulesTotalMetric, rulesTotal)
 	}
@@ -6049,8 +6053,8 @@ func TestSyncProxyRulesRepeated(t *testing.T) {
 		`)
 	assertIPTablesRulesEqual(t, getLine(), false, expected, fp.iptablesData.String())

-	rulesSynced = countRules(utiliptables.TableNAT, expected)
-	rulesSyncedMetric = countRulesFromLastSyncMetric(utiliptables.TableNAT)
+	rulesSynced = countRules(logger, utiliptables.TableNAT, expected)
+	rulesSyncedMetric = countRulesFromLastSyncMetric(logger, utiliptables.TableNAT)
 	if rulesSyncedMetric != rulesSynced {
 		t.Errorf("metric shows %d rules synced but iptables data shows %d", rulesSyncedMetric, rulesSynced)
 	}
@@ -6058,7 +6062,7 @@ func TestSyncProxyRulesRepeated(t *testing.T) {
 	// We deleted 1 KUBE-SERVICES rule, 2 KUBE-SVC-2VJB64SDSIJUP5T6 rules, and 2
 	// KUBE-SEP-UHEGFW77JX3KXTOV rules
 	rulesTotal -= 5
-	rulesTotalMetric = countRulesFromMetric(utiliptables.TableNAT)
+	rulesTotalMetric = countRulesFromMetric(logger, utiliptables.TableNAT)
 	if rulesTotalMetric != rulesTotal {
 		t.Errorf("metric shows %d rules total but expected %d", rulesTotalMetric, rulesTotal)
 	}
@@ -6109,15 +6113,15 @@ func TestSyncProxyRulesRepeated(t *testing.T) {
 		`)
 	assertIPTablesRulesEqual(t, getLine(), false, expected, fp.iptablesData.String())

-	rulesSynced = countRules(utiliptables.TableNAT, expected)
-	rulesSyncedMetric = countRulesFromLastSyncMetric(utiliptables.TableNAT)
+	rulesSynced = countRules(logger, utiliptables.TableNAT, expected)
+	rulesSyncedMetric = countRulesFromLastSyncMetric(logger, utiliptables.TableNAT)
 	if rulesSyncedMetric != rulesSynced {
 		t.Errorf("metric shows %d rules synced but iptables data shows %d", rulesSyncedMetric, rulesSynced)
 	}

 	// The REJECT rule is in "filter", not NAT, so the number of NAT rules hasn't
 	// changed.
-	rulesTotalMetric = countRulesFromMetric(utiliptables.TableNAT)
+	rulesTotalMetric = countRulesFromMetric(logger, utiliptables.TableNAT)
 	if rulesTotalMetric != rulesTotal {
 		t.Errorf("metric shows %d rules total but expected %d", rulesTotalMetric, rulesTotal)
 	}
@@ -6172,8 +6176,8 @@ func TestSyncProxyRulesRepeated(t *testing.T) {
 		`)
 	assertIPTablesRulesEqual(t, getLine(), false, expected, fp.iptablesData.String())

-	rulesSynced = countRules(utiliptables.TableNAT, expected)
-	rulesSyncedMetric = countRulesFromLastSyncMetric(utiliptables.TableNAT)
+	rulesSynced = countRules(logger, utiliptables.TableNAT, expected)
+	rulesSyncedMetric = countRulesFromLastSyncMetric(logger, utiliptables.TableNAT)
 	if rulesSyncedMetric != rulesSynced {
 		t.Errorf("metric shows %d rules synced but iptables data shows %d", rulesSyncedMetric, rulesSynced)
 	}
@@ -6181,7 +6185,7 @@ func TestSyncProxyRulesRepeated(t *testing.T) {
 	// We added 1 KUBE-SERVICES rule, 2 KUBE-SVC-4SW47YFZTEDKD3PK rules, and
 	// 2 KUBE-SEP-AYCN5HPXMIRJNJXU rules
 	rulesTotal += 5
-	rulesTotalMetric = countRulesFromMetric(utiliptables.TableNAT)
+	rulesTotalMetric = countRulesFromMetric(logger, utiliptables.TableNAT)
 	if rulesTotalMetric != rulesTotal {
 		t.Errorf("metric shows %d rules total but expected %d", rulesTotalMetric, rulesTotal)
 	}
@@ -6231,14 +6235,14 @@ func TestSyncProxyRulesRepeated(t *testing.T) {
 		`)
 	assertIPTablesRulesEqual(t, getLine(), false, expected, fp.iptablesData.String())

-	rulesSynced = countRules(utiliptables.TableNAT, expected)
-	rulesSyncedMetric = countRulesFromLastSyncMetric(utiliptables.TableNAT)
+	rulesSynced = countRules(logger, utiliptables.TableNAT, expected)
+	rulesSyncedMetric = countRulesFromLastSyncMetric(logger, utiliptables.TableNAT)
 	if rulesSyncedMetric != rulesSynced {
 		t.Errorf("metric shows %d rules synced but iptables data shows %d", rulesSyncedMetric, rulesSynced)
 	}

 	// We rewrote existing rules but did not change the overall number of rules.
-	rulesTotalMetric = countRulesFromMetric(utiliptables.TableNAT)
+	rulesTotalMetric = countRulesFromMetric(logger, utiliptables.TableNAT)
 	if rulesTotalMetric != rulesTotal {
 		t.Errorf("metric shows %d rules total but expected %d", rulesTotalMetric, rulesTotal)
 	}
@@ -6289,8 +6293,8 @@ func TestSyncProxyRulesRepeated(t *testing.T) {
 		`)
 	assertIPTablesRulesEqual(t, getLine(), false, expected, fp.iptablesData.String())

-	rulesSynced = countRules(utiliptables.TableNAT, expected)
-	rulesSyncedMetric = countRulesFromLastSyncMetric(utiliptables.TableNAT)
+	rulesSynced = countRules(logger, utiliptables.TableNAT, expected)
+	rulesSyncedMetric = countRulesFromLastSyncMetric(logger, utiliptables.TableNAT)
 	if rulesSyncedMetric != rulesSynced {
 		t.Errorf("metric shows %d rules synced but iptables data shows %d", rulesSyncedMetric, rulesSynced)
 	}
@@ -6299,7 +6303,7 @@ func TestSyncProxyRulesRepeated(t *testing.T) {
 	// jumping to the new SEP chain. The other rules related to svc3 got rewritten,
 	// but that does not change the count of rules.
 	rulesTotal += 3
-	rulesTotalMetric = countRulesFromMetric(utiliptables.TableNAT)
+	rulesTotalMetric = countRulesFromMetric(logger, utiliptables.TableNAT)
 	if rulesTotalMetric != rulesTotal {
 		t.Errorf("metric shows %d rules total but expected %d", rulesTotalMetric, rulesTotal)
 	}
@@ -6337,14 +6341,14 @@ func TestSyncProxyRulesRepeated(t *testing.T) {
 		`)
 	assertIPTablesRulesEqual(t, getLine(), false, expected, fp.iptablesData.String())

-	rulesSynced = countRules(utiliptables.TableNAT, expected)
-	rulesSyncedMetric = countRulesFromLastSyncMetric(utiliptables.TableNAT)
+	rulesSynced = countRules(logger, utiliptables.TableNAT, expected)
+	rulesSyncedMetric = countRulesFromLastSyncMetric(logger, utiliptables.TableNAT)
 	if rulesSyncedMetric != rulesSynced {
 		t.Errorf("metric shows %d rules synced but iptables data shows %d", rulesSyncedMetric, rulesSynced)
 	}

 	// (No changes)
-	rulesTotalMetric = countRulesFromMetric(utiliptables.TableNAT)
+	rulesTotalMetric = countRulesFromMetric(logger, utiliptables.TableNAT)
 	if rulesTotalMetric != rulesTotal {
 		t.Errorf("metric shows %d rules total but expected %d", rulesTotalMetric, rulesTotal)
 	}
@@ -6447,8 +6451,8 @@ func TestSyncProxyRulesRepeated(t *testing.T) {
 		`)
 	assertIPTablesRulesEqual(t, getLine(), false, expected, fp.iptablesData.String())

-	rulesSynced = countRules(utiliptables.TableNAT, expected)
-	rulesSyncedMetric = countRulesFromLastSyncMetric(utiliptables.TableNAT)
+	rulesSynced = countRules(logger, utiliptables.TableNAT, expected)
+	rulesSyncedMetric = countRulesFromLastSyncMetric(logger, utiliptables.TableNAT)
 	if rulesSyncedMetric != rulesSynced {
 		t.Errorf("metric shows %d rules synced but iptables data shows %d", rulesSyncedMetric, rulesSynced)
 	}
@@ -6456,7 +6460,7 @@ func TestSyncProxyRulesRepeated(t *testing.T) {
 	// We deleted 1 KUBE-SERVICES rule, 2 KUBE-SVC-4SW47YFZTEDKD3PK rules, and 2
 	// KUBE-SEP-AYCN5HPXMIRJNJXU rules
 	rulesTotal -= 5
-	rulesTotalMetric = countRulesFromMetric(utiliptables.TableNAT)
+	rulesTotalMetric = countRulesFromMetric(logger, utiliptables.TableNAT)
 	if rulesTotalMetric != rulesTotal {
 		t.Errorf("metric shows %d rules total but expected %d", rulesTotalMetric, rulesTotal)
 	}