Merge pull request #108224 from danwinship/kube-proxy-logging

Only log full iptables-restore input at V(9)

pkg/proxy/iptables/proxier.go

@@ -893,10 +893,6 @@ func (proxier *Proxier) syncProxyRules() {
 	proxier.natChains.Reset()
 	proxier.natRules.Reset()
 
-	// Write table headers.
-	proxier.filterChains.Write("*filter")
-	proxier.natChains.Write("*nat")
-
 	// Make sure we keep stats for the top-level chains, if they existed
 	// (which most should have because we created them above).
 	for _, chainName := range []utiliptables.Chain{kubeServicesChain, kubeExternalServicesChain, kubeForwardChain, kubeNodePortsChain} {
@@ -1507,24 +1503,31 @@ func (proxier *Proxier) syncProxyRules() {
 		"-j", "ACCEPT",
 	)
 
-	numberFilterIptablesRules := utilproxy.CountBytesLines(proxier.filterRules.Bytes())
-	metrics.IptablesRulesTotal.WithLabelValues(string(utiliptables.TableFilter)).Set(float64(numberFilterIptablesRules))
-	numberNatIptablesRules := utilproxy.CountBytesLines(proxier.natRules.Bytes())
-	metrics.IptablesRulesTotal.WithLabelValues(string(utiliptables.TableNAT)).Set(float64(numberNatIptablesRules))
-
-	// Write the end-of-table markers.
-	proxier.filterRules.Write("COMMIT")
-	proxier.natRules.Write("COMMIT")
+	metrics.IptablesRulesTotal.WithLabelValues(string(utiliptables.TableFilter)).Set(float64(proxier.filterRules.Lines()))
+	metrics.IptablesRulesTotal.WithLabelValues(string(utiliptables.TableNAT)).Set(float64(proxier.natRules.Lines()))
 
 	// Sync rules.
-	// NOTE: NoFlushTables is used so we don't flush non-kubernetes chains in the table
 	proxier.iptablesData.Reset()
+	proxier.iptablesData.WriteString("*filter\n")
 	proxier.iptablesData.Write(proxier.filterChains.Bytes())
 	proxier.iptablesData.Write(proxier.filterRules.Bytes())
+	proxier.iptablesData.WriteString("COMMIT\n")
+	proxier.iptablesData.WriteString("*nat\n")
 	proxier.iptablesData.Write(proxier.natChains.Bytes())
 	proxier.iptablesData.Write(proxier.natRules.Bytes())
+	proxier.iptablesData.WriteString("COMMIT\n")
 
-	klog.V(5).InfoS("Restoring iptables", "rules", proxier.iptablesData.Bytes())
+	klog.V(2).InfoS("Reloading service iptables data",
+		"numServices", len(proxier.serviceMap),
+		"numEndpoints", proxier.endpointChainsNumber,
+		"numFilterChains", proxier.filterChains.Lines(),
+		"numFilterRules", proxier.filterRules.Lines(),
+		"numNATChains", proxier.natChains.Lines(),
+		"numNATRules", proxier.natRules.Lines(),
+	)
+	klog.V(9).InfoS("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 {

pkg/proxy/util/utils.go

@@ -521,7 +521,8 @@ func GetClusterIPByFamily(ipFamily v1.IPFamily, service *v1.Service) string {
 }
 
 type LineBuffer struct {
-	b bytes.Buffer
+	b     bytes.Buffer
+	lines int
 }
 
 // Write takes a list of arguments, each a string or []string, joins all the
@@ -547,22 +548,34 @@ func (buf *LineBuffer) Write(args ...interface{}) {
 		}
 	}
 	buf.b.WriteByte('\n')
+	buf.lines++
 }
 
 // WriteBytes writes bytes to buffer, and terminates with newline.
 func (buf *LineBuffer) WriteBytes(bytes []byte) {
 	buf.b.Write(bytes)
 	buf.b.WriteByte('\n')
+	buf.lines++
 }
 
+// Reset clears buf
 func (buf *LineBuffer) Reset() {
 	buf.b.Reset()
+	buf.lines = 0
 }
 
+// Bytes returns the contents of buf as a []byte
 func (buf *LineBuffer) Bytes() []byte {
 	return buf.b.Bytes()
 }
 
+// Lines returns the number of lines in buf. Note that more precisely, this returns the
+// number of times Write() or WriteBytes() was called; it assumes that you never wrote
+// any newlines to the buffer yourself.
+func (buf *LineBuffer) Lines() int {
+	return buf.lines
+}
+
 // RevertPorts is closing ports in replacementPortsMap but not in originalPortsMap. In other words, it only
 // closes the ports opened in this sync.
 func RevertPorts(replacementPortsMap, originalPortsMap map[netutils.LocalPort]netutils.Closeable) {
@@ -574,8 +587,3 @@ func RevertPorts(replacementPortsMap, originalPortsMap map[netutils.LocalPort]ne
 		}
 	}
 }
-
-// CountBytesLines counts the number of lines in a bytes slice
-func CountBytesLines(b []byte) int {
-	return bytes.Count(b, []byte{'\n'})
-}

pkg/proxy/util/utils_test.go

@@ -1185,6 +1185,9 @@ func TestLineBufferWrite(t *testing.T) {
 			if want, got := testCase.expected, string(testBuffer.Bytes()); !strings.EqualFold(want, got) {
 				t.Fatalf("write word is %v\n expected: %q, got: %q", testCase.input, want, got)
 			}
+			if testBuffer.Lines() != 1 {
+				t.Fatalf("expected 1 line, got: %d", testBuffer.Lines())
+			}
 		})
 	}
 }
@@ -1267,7 +1270,7 @@ func TestWriteCountLines(t *testing.T) {
 			for i := 0; i < testCase.expected; i++ {
 				testBuffer.Write(randSeq())
 			}
-			n := CountBytesLines(testBuffer.Bytes())
+			n := testBuffer.Lines()
 			if n != testCase.expected {
 				t.Fatalf("lines expected: %d, got: %d", testCase.expected, n)
 			}