From d7ce7cccbcd98aa17515d9fd449c88807cb6f0bd Mon Sep 17 00:00:00 2001
From: Sean Dague <sean@dague.net>
Date: Thu, 3 Jul 2014 08:00:39 -0400
Subject: [PATCH] change the firewall debugging for clarity

When we are building rules ensure we log the instance['id'] so
we can actually correlate the iptables output to UUID for the
instance.

Also bundle up the security group to iptables translation to a
final view of the world instead of the piecemeal rule at a time
view.

Display what rules are being skipped in the add process, as the
skips seem to happen a lot. If this is completely normal we should
probably delete the bit entirely at some later point.

Related-Bug: #1298472

Change-Id: I0e90c3af9bf908b733ed895ad7c204b0a95ef786
---
 nova/network/linux_net.py |  4 +++-
 nova/virt/firewall.py     | 15 ++++++---------
 2 files changed, 9 insertions(+), 10 deletions(-)

diff --git a/nova/network/linux_net.py b/nova/network/linux_net.py
index c75a364c352f..010574c04294 100644
--- a/nova/network/linux_net.py
+++ b/nova/network/linux_net.py
@@ -267,7 +267,9 @@ class IptablesTable(object):
 
         rule_obj = IptablesRule(chain, rule, wrap, top)
         if rule_obj in self.rules:
-            LOG.debug("Skipping duplicate iptables rule addition")
+            LOG.debug("Skipping duplicate iptables rule addition. "
+                      "%(rule)r already in %(rules)r",
+                      {'rule': rule_obj, 'rules': self.rules})
         else:
             self.rules.append(IptablesRule(chain, rule, wrap, top))
             self.dirty = True
diff --git a/nova/virt/firewall.py b/nova/virt/firewall.py
index 1c8f144e3653..4f3825554e2a 100644
--- a/nova/virt/firewall.py
+++ b/nova/virt/firewall.py
@@ -180,9 +180,11 @@ class IptablesFirewallDriver(FirewallDriver):
         ipv4_rules, ipv6_rules = self.instance_rules(instance, network_info)
         self.add_filters_for_instance(instance, network_info, ipv4_rules,
                                       ipv6_rules)
-        LOG.debug('Filters added to instance', instance=instance)
+        LOG.debug('Filters added to instance: %s', instance['id'],
+                  instance=instance)
         self.refresh_provider_fw_rules()
-        LOG.debug('Provider Firewall Rules refreshed', instance=instance)
+        LOG.debug('Provider Firewall Rules refreshed: %s', instance['id'],
+                  instance=instance)
         # Ensure that DHCP request rule is updated if necessary
         if (self.dhcp_create and not self.dhcp_created):
             self.iptables.ipv4['filter'].add_rule(
@@ -363,9 +365,6 @@ class IptablesFirewallDriver(FirewallDriver):
             rules = rules_cls.get_by_security_group(ctxt, security_group)
 
             for rule in rules:
-                LOG.debug('Adding security group rule: %r', rule,
-                          instance=instance)
-
                 if not rule['cidr']:
                     version = 4
                 else:
@@ -393,7 +392,6 @@ class IptablesFirewallDriver(FirewallDriver):
                 elif protocol == 'icmp':
                     args += self._build_icmp_rule(rule, version)
                 if rule['cidr']:
-                    LOG.debug('Using cidr %r', rule['cidr'], instance=instance)
                     args += ['-s', str(rule['cidr'])]
                     fw_rules += [' '.join(args)]
                 else:
@@ -417,11 +415,10 @@ class IptablesFirewallDriver(FirewallDriver):
                                 subrule = args + ['-s %s' % ip]
                                 fw_rules += [' '.join(subrule)]
 
-                LOG.debug('Using fw_rules: %r', fw_rules, instance=instance)
-
         ipv4_rules += ['-j $sg-fallback']
         ipv6_rules += ['-j $sg-fallback']
-
+        LOG.debug('Security Groups %s translated to ipv4: %r, ipv6: %r',
+            security_groups, ipv4_rules, ipv6_rules, instance=instance)
         return ipv4_rules, ipv6_rules
 
     def instance_filter_exists(self, instance, network_info):