Improve logging in Agent's NetworkPolicy controller

pkg/agent/controller/networkpolicy/fqdn.go

@@ -350,6 +350,10 @@ func (f *fqdnController) deleteFQDNRule(ruleID string, fqdns []string) error {
 }
 
 func (f *fqdnController) deleteFQDNSelector(ruleID string, fqdns []string) {
+	// No need to lock the mutex if fqdns is empty.
+	if len(fqdns) == 0 {
+		return
+	}
 	f.fqdnSelectorMutex.Lock()
 	defer f.fqdnSelectorMutex.Unlock()
 	for _, fqdn := range fqdns {

pkg/agent/controller/networkpolicy/networkpolicy_controller.go

@@ -349,7 +349,7 @@ func NewNetworkPolicyController(antreaClientGetter client.AntreaClientProvider,
 				return nil
 			}
 			c.ruleCache.DeleteNetworkPolicy(policy)
-			klog.InfoS("NetworkPolicy no longer applied to Pods on this Node", "policyName", policy.SourceRef.ToString())
+			klog.InfoS("NetworkPolicy no longer applied to Pods on this Node or the Node itself", "policyName", policy.SourceRef.ToString())
 			if err := c.networkPolicyStore.save(policy); err != nil {
 				klog.ErrorS(err, "Failed to delete the NetworkPolicy from file", "policyName", policy.SourceRef.ToString())
 			}
@@ -368,7 +368,7 @@ func NewNetworkPolicyController(antreaClientGetter client.AntreaClientProvider,
 						"policyName", policies[i].SourceRef.ToString())
 					return nil
 				}
-				klog.InfoS("NetworkPolicy applied to Pods on this Node", "policyName", policies[i].SourceRef.ToString())
+				klog.InfoS("NetworkPolicy applied to Pods on this Node or the Node itself", "policyName", policies[i].SourceRef.ToString())
 				// When ReplaceFunc is called, either the controller restarted or this was a regular reconnection.
 				// For the former case, agent must resync the statuses as the controller lost the previous statuses.
 				// For the latter case, agent doesn't need to do anything. However, we are not able to differentiate the

pkg/agent/controller/networkpolicy/node_reconciler_linux.go

@@ -156,6 +156,8 @@ func newCoreIPTChain() *coreIPTChain {
 // nodePolicyLastRealized is the struct cached by nodeReconciler. It's used to track the actual state of iptables rules
 // and chains we have enforced, so that we can know how to reconcile a rule when it's updated/removed.
 type nodePolicyLastRealized struct {
+	// The desired state of a policy rule.
+	*CompletedRule
 	// ipsets tracks the last realized ipset names used in core iptables rules. It cannot coexist with ipnets.
 	ipsets map[iptables.Protocol]string
 	// ipnets tracks the last realized ip nets used in core iptables rules. It cannot coexist with ipsets.
@@ -166,10 +168,11 @@ type nodePolicyLastRealized struct {
 	coreIPTChain string
 }
 
-func newNodePolicyLastRealized() *nodePolicyLastRealized {
+func newNodePolicyLastRealized(rule *CompletedRule) *nodePolicyLastRealized {
 	return &nodePolicyLastRealized{
-		ipsets: make(map[iptables.Protocol]string),
-		ipnets: make(map[iptables.Protocol]string),
+		CompletedRule: rule,
+		ipsets:        make(map[iptables.Protocol]string),
+		ipnets:        make(map[iptables.Protocol]string),
 	}
 }
 
@@ -205,7 +208,7 @@ func newNodeReconciler(routeClient route.Interface, ipv4Enabled, ipv6Enabled boo
 
 // Reconcile checks whether the provided rule has been enforced or not, and invoke the add or update method accordingly.
 func (r *nodeReconciler) Reconcile(rule *CompletedRule) error {
-	klog.InfoS("Reconciling Node NetworkPolicy rule", "rule", rule.ID, "policy", rule.SourceRef.ToString())
+	klog.V(1).InfoS("Reconciling Node NetworkPolicy rule", "rule", rule.ID, "policy", rule.SourceRef.ToString())
 
 	value, exists := r.lastRealizeds.Load(rule.ID)
 	var err error
@@ -289,16 +292,18 @@ func (r *nodeReconciler) batchAdd(rules []*CompletedRule) error {
 }
 
 func (r *nodeReconciler) Forget(ruleID string) error {
-	klog.InfoS("Forgetting rule", "rule", ruleID)
-
 	value, exists := r.lastRealizeds.Load(ruleID)
 	if !exists {
+		// No-op if the rule was not realized before.
+		klog.V(4).InfoS("Trying to forget unrealized Node NetworkPolicy rule, no action needed", "rule", ruleID)
 		return nil
 	}
 
 	lastRealized := value.(*nodePolicyLastRealized)
-	coreIPTChain := lastRealized.coreIPTChain
 
+	klog.V(1).InfoS("Forgetting Node NetworkPolicy rule", "rule", ruleID, "policy", lastRealized.CompletedRule.SourceRef.ToString())
+
+	coreIPTChain := lastRealized.coreIPTChain
 	for _, ipProtocol := range r.ipProtocols {
 		isIPv6 := iptables.IsIPv6Protocol(ipProtocol)
 		if err := r.deleteCoreIPTRule(ruleID, coreIPTChain, isIPv6); err != nil {
@@ -331,7 +336,7 @@ func (r *nodeReconciler) computeIPTRules(rule *CompletedRule) (map[iptables.Prot
 	if enableLogging {
 		logLabel = generateLogLabel(rule)
 	}
-	lastRealized := newNodePolicyLastRealized()
+	lastRealized := newNodePolicyLastRealized(rule)
 	priority := &types.Priority{
 		TierPriority:   *rule.TierPriority,
 		PolicyPriority: *rule.PolicyPriority,

pkg/agent/controller/networkpolicy/pod_reconciler.go

@@ -295,7 +295,7 @@ func (r *podReconciler) RunIDAllocatorWorker(stopCh <-chan struct{}) {
 // Reconcile checks whether the provided rule has been enforced or not, and
 // invoke the add or update method accordingly.
 func (r *podReconciler) Reconcile(rule *CompletedRule) error {
-	klog.InfoS("Reconciling Pod NetworkPolicy rule", "rule", rule.ID, "policy", rule.SourceRef.ToString())
+	klog.V(1).InfoS("Reconciling Pod NetworkPolicy rule", "rule", rule.ID, "policy", rule.SourceRef.ToString())
 	var err error
 	var ofPriority *uint16
 
@@ -1005,15 +1005,17 @@ func (r *podReconciler) uninstallOFRule(ofID uint32, table uint8) error {
 // Forget invokes UninstallPolicyRuleFlows to uninstall Openflow entries
 // associated with the provided ruleID if it was enforced before.
 func (r *podReconciler) Forget(ruleID string) error {
-	klog.InfoS("Forgetting rule", "rule", ruleID)
-
 	value, exists := r.lastRealizeds.Load(ruleID)
 	if !exists {
 		// No-op if the rule was not realized before.
+		klog.V(4).InfoS("Trying to forget unrealized Pod NetworkPolicy rule, no action needed", "rule", ruleID)
 		return nil
 	}
 
 	lastRealized := value.(*podPolicyLastRealized)
+
+	klog.V(1).InfoS("Forgetting Pod NetworkPolicy rule", "rule", ruleID, "policy", lastRealized.CompletedRule.SourceRef.ToString())
+
 	table := r.getOFRuleTable(lastRealized.CompletedRule)
 	priorityAssigner, exists := r.priorityAssigners[table]
 	if exists {