Enforce log hints in neutron.plugins.hyperv

This change enforces log hints use and removes debug level log
translation, modifications are validated through a hacking rule and
the change respects loggging guidelines.

Validate that hacking rules apply to directories:
    - neutron/plugins/hyperv

Change-Id: Iea2d63a4e74bf824ee308057570c980c50e937bc
Partial-bug: #1320867

neutron/hacking/checks.py

@@ -79,7 +79,7 @@ def _directory_to_check_translation(filename):
             "neutron/plugins/cisco",
             "neutron/plugins/common",
             #"neutron/plugins/embrane",
-            #"neutron/plugins/hyperv",
+            "neutron/plugins/hyperv",
             #"neutron/plugins/ibm",
             "neutron/plugins/linuxbridge",
             #"neutron/plugins/metaplugin",

neutron/plugins/hyperv/agent/hyperv_neutron_agent.py

@@ -33,6 +33,7 @@
 from neutron.common import rpc as n_rpc
 from neutron.common import topics
 from neutron import context
+from neutron.i18n import _LE, _LI
 from neutron.openstack.common import log as logging
 from neutron.openstack.common import loopingcall
 from neutron.plugins.common import constants as p_const
@@ -146,8 +147,8 @@ def _report_state(self):
             self.state_rpc.report_state(self.context,
                                         self.agent_state)
             self.agent_state.pop('start_flag', None)
-        except Exception as ex:
-            LOG.exception(_("Failed reporting state! %s"), ex)
+        except Exception:
+            LOG.exception(_LE("Failed reporting state!"))
 
     def _setup_rpc(self):
         self.agent_id = 'hyperv_%s' % platform.node()
@@ -182,7 +183,7 @@ def _load_physical_network_mappings(self):
         for mapping in CONF.AGENT.physical_network_vswitch_mappings:
             parts = mapping.split(':')
             if len(parts) != 2:
-                LOG.debug(_('Invalid physical network mapping: %s'), mapping)
+                LOG.debug('Invalid physical network mapping: %s', mapping)
             else:
                 pattern = re.escape(parts[0].strip()).replace('\\*', '.*')
                 vswitch = parts[1].strip()
@@ -203,21 +204,21 @@ def _get_network_vswitch_map_by_port_id(self, port_id):
                 return (network_id, map)
 
     def network_delete(self, context, network_id=None):
-        LOG.debug(_("network_delete received. "
-                    "Deleting network %s"), network_id)
+        LOG.debug("network_delete received. "
+                  "Deleting network %s", network_id)
         # The network may not be defined on this agent
         if network_id in self._network_vswitch_map:
             self._reclaim_local_network(network_id)
         else:
-            LOG.debug(_("Network %s not defined on agent."), network_id)
+            LOG.debug("Network %s not defined on agent.", network_id)
 
     def port_delete(self, context, port_id=None):
-        LOG.debug(_("port_delete received"))
+        LOG.debug("port_delete received")
         self._port_unbound(port_id)
 
     def port_update(self, context, port=None, network_type=None,
                     segmentation_id=None, physical_network=None):
-        LOG.debug(_("port_update received"))
+        LOG.debug("port_update received")
         if CONF.SECURITYGROUP.enable_security_group:
             if 'security_groups' in port:
                 self.sec_groups_agent.refresh_firewall()
@@ -239,7 +240,7 @@ def _provision_network(self, port_id,
                            net_uuid, network_type,
                            physical_network,
                            segmentation_id):
-        LOG.info(_("Provisioning network %s"), net_uuid)
+        LOG.info(_LI("Provisioning network %s"), net_uuid)
 
         vswitch_name = self._get_vswitch_name(network_type, physical_network)
 
@@ -264,15 +265,15 @@ def _provision_network(self, port_id,
         self._network_vswitch_map[net_uuid] = map
 
     def _reclaim_local_network(self, net_uuid):
-        LOG.info(_("Reclaiming local network %s"), net_uuid)
+        LOG.info(_LI("Reclaiming local network %s"), net_uuid)
         del self._network_vswitch_map[net_uuid]
 
     def _port_bound(self, port_id,
                     net_uuid,
                     network_type,
                     physical_network,
                     segmentation_id):
-        LOG.debug(_("Binding port %s"), port_id)
+        LOG.debug("Binding port %s", port_id)
 
         if net_uuid not in self._network_vswitch_map:
             self._provision_network(
@@ -285,8 +286,8 @@ def _port_bound(self, port_id,
         self._utils.connect_vnic_to_vswitch(map['vswitch_name'], port_id)
 
         if network_type == p_const.TYPE_VLAN:
-            LOG.info(_('Binding VLAN ID %(segmentation_id)s '
-                       'to switch port %(port_id)s'),
+            LOG.info(_LI('Binding VLAN ID %(segmentation_id)s '
+                         'to switch port %(port_id)s'),
                      dict(segmentation_id=segmentation_id, port_id=port_id))
             self._utils.set_vswitch_port_vlan_id(
                 segmentation_id,
@@ -298,7 +299,7 @@ def _port_bound(self, port_id,
             #Nothing to do
             pass
         else:
-            LOG.error(_('Unsupported network type %s'), network_type)
+            LOG.error(_LE('Unsupported network type %s'), network_type)
 
         if CONF.AGENT.enable_metrics_collection:
             self._utils.enable_port_metrics_collection(port_id)
@@ -307,11 +308,11 @@ def _port_bound(self, port_id,
     def _port_unbound(self, port_id):
         (net_uuid, map) = self._get_network_vswitch_map_by_port_id(port_id)
         if net_uuid not in self._network_vswitch_map:
-            LOG.info(_('Network %s is not avalailable on this agent'),
+            LOG.info(_LI('Network %s is not avalailable on this agent'),
                      net_uuid)
             return
 
-        LOG.debug(_("Unbinding port %s"), port_id)
+        LOG.debug("Unbinding port %s", port_id)
         self._utils.disconnect_switch_port(map['vswitch_name'], port_id, True)
 
         if not map['ports']:
@@ -324,11 +325,12 @@ def _port_enable_control_metrics(self):
         for port_id in self._port_metric_retries.keys():
             if self._utils.can_enable_control_metrics(port_id):
                 self._utils.enable_control_metrics(port_id)
-                LOG.info(_('Port metrics enabled for port: %s'), port_id)
+                LOG.info(_LI('Port metrics enabled for port: %s'), port_id)
                 del self._port_metric_retries[port_id]
             elif self._port_metric_retries[port_id] < 1:
                 self._utils.enable_control_metrics(port_id)
-                LOG.error(_('Port metrics raw enabling for port: %s'), port_id)
+                LOG.error(_LE('Port metrics raw enabling for port: %s'),
+                          port_id)
                 del self._port_metric_retries[port_id]
             else:
                 self._port_metric_retries[port_id] -= 1
@@ -353,7 +355,7 @@ def _treat_vif_port(self, port_id, network_id, network_type,
             else:
                 self._port_unbound(port_id)
         else:
-            LOG.debug(_("No port %s defined on agent."), port_id)
+            LOG.debug("No port %s defined on agent.", port_id)
 
     def _treat_devices_added(self, devices):
         try:
@@ -370,11 +372,11 @@ def _treat_devices_added(self, devices):
 
         for device_details in devices_details_list:
             device = device_details['device']
-            LOG.info(_("Adding port %s"), device)
+            LOG.info(_LI("Adding port %s"), device)
             if 'port_id' in device_details:
-                LOG.info(
-                    _("Port %(device)s updated. Details: %(device_details)s"),
-                    {'device': device, 'device_details': device_details})
+                LOG.info(_LI("Port %(device)s updated. Details: "
+                             "%(device_details)s"),
+                         {'device': device, 'device_details': device_details})
                 self._treat_vif_port(
                     device_details['port_id'],
                     device_details['network_id'],
@@ -399,16 +401,15 @@ def _treat_devices_added(self, devices):
     def _treat_devices_removed(self, devices):
         resync = False
         for device in devices:
-            LOG.info(_("Removing port %s"), device)
+            LOG.info(_LI("Removing port %s"), device)
             try:
                 self.plugin_rpc.update_device_down(self.context,
                                                    device,
                                                    self.agent_id,
                                                    cfg.CONF.host)
             except Exception as e:
-                LOG.debug(
-                    _("Removing port failed for device %(device)s: %(e)s"),
-                    dict(device=device, e=e))
+                LOG.debug("Removing port failed for device %(device)s: %(e)s",
+                          dict(device=device, e=e))
                 resync = True
                 continue
             self._port_unbound(device)
@@ -432,31 +433,31 @@ def daemon_loop(self):
             try:
                 start = time.time()
                 if sync:
-                    LOG.info(_("Agent out of sync with plugin!"))
+                    LOG.info(_LI("Agent out of sync with plugin!"))
                     ports.clear()
                     sync = False
 
                 port_info = self._update_ports(ports)
 
                 # notify plugin about port deltas
                 if port_info:
-                    LOG.debug(_("Agent loop has new devices!"))
+                    LOG.debug("Agent loop has new devices!")
                     # If treat devices fails - must resync with plugin
                     sync = self._process_network_ports(port_info)
                     ports = port_info['current']
 
                 self._port_enable_control_metrics()
-            except Exception as e:
-                LOG.exception(_("Error in agent event loop: %s"), e)
+            except Exception:
+                LOG.exception(_LE("Error in agent event loop"))
                 sync = True
 
             # sleep till end of polling interval
             elapsed = (time.time() - start)
             if (elapsed < self._polling_interval):
                 time.sleep(self._polling_interval - elapsed)
             else:
-                LOG.debug(_("Loop iteration exceeded interval "
-                            "(%(polling_interval)s vs. %(elapsed)s)"),
+                LOG.debug("Loop iteration exceeded interval "
+                          "(%(polling_interval)s vs. %(elapsed)s)",
                           {'polling_interval': self._polling_interval,
                            'elapsed': elapsed})
 
@@ -468,5 +469,5 @@ def main():
     plugin = HyperVNeutronAgent()
 
     # Start everything.
-    LOG.info(_("Agent initialized successfully, now running... "))
+    LOG.info(_LI("Agent initialized successfully, now running... "))
     plugin.daemon_loop()

neutron/plugins/hyperv/agent/security_groups_driver.py

@@ -14,6 +14,7 @@
 #    under the License.
 
 from neutron.agent import firewall
+from neutron.i18n import _LE, _LI
 from neutron.openstack.common import log as logging
 from neutron.plugins.hyperv.agent import utilsfactory
 from neutron.plugins.hyperv.agent import utilsv2
@@ -42,7 +43,7 @@ def __init__(self):
         self._security_ports = {}
 
     def prepare_port_filter(self, port):
-        LOG.debug('Creating port %s rules' % len(port['security_group_rules']))
+        LOG.debug('Creating port %s rules', len(port['security_group_rules']))
 
         # newly created port, add default rules.
         if port['device'] not in self._security_ports:
@@ -58,8 +59,8 @@ def _create_port_rules(self, port_id, rules):
             try:
                 self._utils.create_security_rule(port_id, **param_map)
             except Exception as ex:
-                LOG.error(_('Hyper-V Exception: %(hyperv_exeption)s while '
-                            'adding rule: %(rule)s'),
+                LOG.error(_LE('Hyper-V Exception: %(hyperv_exeption)s while '
+                              'adding rule: %(rule)s'),
                           dict(hyperv_exeption=ex, rule=rule))
 
     def _remove_port_rules(self, port_id, rules):
@@ -68,8 +69,8 @@ def _remove_port_rules(self, port_id, rules):
             try:
                 self._utils.remove_security_rule(port_id, **param_map)
             except Exception as ex:
-                LOG.error(_('Hyper-V Exception: %(hyperv_exeption)s while '
-                            'removing rule: %(rule)s'),
+                LOG.error(_LE('Hyper-V Exception: %(hyperv_exeption)s while '
+                              'removing rule: %(rule)s'),
                           dict(hyperv_exeption=ex, rule=rule))
 
     def _create_param_map(self, rule):
@@ -88,10 +89,10 @@ def _create_param_map(self, rule):
         }
 
     def apply_port_filter(self, port):
-        LOG.info(_('Aplying port filter.'))
+        LOG.info(_LI('Aplying port filter.'))
 
     def update_port_filter(self, port):
-        LOG.info(_('Updating port rules.'))
+        LOG.info(_LI('Updating port rules.'))
 
         if port['device'] not in self._security_ports:
             self.prepare_port_filter(port)
@@ -104,18 +105,17 @@ def update_port_filter(self, port):
         new_rules = [r for r in param_port_rules if r not in rules]
         remove_rules = [r for r in rules if r not in param_port_rules]
 
-        LOG.info(_("Creating %(new)s new rules, removing %(old)s "
-                   "old rules."),
-                 {'new': len(new_rules),
-                  'old': len(remove_rules)})
+        LOG.info(_LI("Creating %(new)s new rules, removing %(old)s "
+                     "old rules."),
+                 {'new': len(new_rules), 'old': len(remove_rules)})
 
         self._remove_port_rules(old_port['id'], remove_rules)
         self._create_port_rules(port['id'], new_rules)
 
         self._security_ports[port['device']] = port
 
     def remove_port_filter(self, port):
-        LOG.info(_('Removing port filter'))
+        LOG.info(_LI('Removing port filter'))
         self._security_ports.pop(port['device'], None)
 
     @property

neutron/plugins/hyperv/agent/utils.py

@@ -148,7 +148,7 @@ def _check_job_status(self, ret_val, jobpath):
 
         desc = job.Description
         elap = job.ElapsedTime
-        LOG.debug(_("WMI job succeeded: %(desc)s, Elapsed=%(elap)s"),
+        LOG.debug("WMI job succeeded: %(desc)s, Elapsed=%(elap)s",
                   {'desc': desc, 'elap': elap})
 
     def _create_switch_port(self, vswitch_name, switch_port_name):

neutron/plugins/hyperv/agent/utilsfactory.py

@@ -17,6 +17,7 @@
 
 from oslo.config import cfg
 
+from neutron.i18n import _LW
 from neutron.openstack.common import log as logging
 from neutron.plugins.hyperv.agent import utils
 from neutron.plugins.hyperv.agent import utilsv2
@@ -57,13 +58,14 @@ def get_hypervutils():
     force_v1_flag = CONF.hyperv.force_hyperv_utils_v1
     if _check_min_windows_version(6, 3):
         if force_v1_flag:
-            LOG.warning(_('V1 virtualization namespace no longer supported on '
-                          'Windows Server / Hyper-V Server 2012 R2 or above.'))
+            LOG.warning(_LW('V1 virtualization namespace no longer supported '
+                            'on Windows Server / Hyper-V Server 2012 R2 or '
+                            'above.'))
         cls = utilsv2.HyperVUtilsV2R2
     elif not force_v1_flag and _check_min_windows_version(6, 2):
         cls = utilsv2.HyperVUtilsV2
     else:
         cls = utils.HyperVUtils
-    LOG.debug(_("Loading class: %(module_name)s.%(class_name)s"),
+    LOG.debug("Loading class: %(module_name)s.%(class_name)s",
               {'module_name': cls.__module__, 'class_name': cls.__name__})
     return cls()

neutron/plugins/hyperv/agent_notifier_api.py

@@ -17,11 +17,8 @@
 
 from neutron.common import rpc as n_rpc
 from neutron.common import topics
-from neutron.openstack.common import log as logging
 from neutron.plugins.hyperv.common import constants
 
-LOG = logging.getLogger(__name__)
-
 
 class AgentNotifierApi(object):
     '''Agent side of the openvswitch rpc API.