yahoo-eng-team team mailing list archive

[Brian Haley <1642770@xxxxxxxxxxxxxxxxxx>]

Public bug reported:

The security group code is generating a lot of these messages when
trying to boot VMs:

Attempted to remove chain sg-chain which does not exist

There's also ones specific to the port.  It seems to be calling
remove_chain(), even when it's a new port and it's initially setting up
it's filter.  I dropped a print_stack() in remove_chain() and see
tracebacks like this:

Prepare port filter for e8f41910-c24e-41f1-ae7f-355e9bb1d18a _apply_port_filter /opt/stack/neutron/neutron/agent/securitygroups_rpc.py:163
Preparing device (e8f41910-c24e-41f1-ae7f-355e9bb1d18a) filter prepare_port_filter /opt/stack/neutron/neutron/agent/linux/iptables_firewall.py:170
Attempted to remove chain sg-chain which does not exist remove_chain /opt/stack/neutron/neutron/agent/linux/iptables_manager.py:177
  File "/usr/local/lib/python2.7/dist-packages/eventlet/greenthread.py", line 214, in main
    result = function(*args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/ryu/lib/hub.py", line 54, in _launch
    return func(*args, **kwargs)
  File "/opt/stack/neutron/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/ovs_ryuapp.py", line 37, in agent_main_wrapper
    ovs_agent.main(bridge_classes)
  File "/opt/stack/neutron/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py", line 2177, in main
    agent.daemon_loop()
  File "/usr/local/lib/python2.7/dist-packages/osprofiler/profiler.py", line 154, in wrapper
    return f(*args, **kwargs)
  File "/opt/stack/neutron/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py", line 2098, in daemon_loop
    self.rpc_loop(polling_manager=pm)
  File "/usr/local/lib/python2.7/dist-packages/osprofiler/profiler.py", line 154, in wrapper
    return f(*args, **kwargs)
  File "/opt/stack/neutron/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py", line 2049, in rpc_loop
    port_info, ovs_restarted)
  File "/usr/local/lib/python2.7/dist-packages/osprofiler/profiler.py", line 154, in wrapper
    return f(*args, **kwargs)
  File "/opt/stack/neutron/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py", line 1657, in process_network_ports
    port_info.get('updated', set()))
  File "/opt/stack/neutron/neutron/agent/securitygroups_rpc.py", line 266, in setup_port_filters
    self.prepare_devices_filter(new_devices)
  File "/opt/stack/neutron/neutron/agent/securitygroups_rpc.py", line 131, in decorated_function
    *args, **kwargs)
  File "/opt/stack/neutron/neutron/agent/securitygroups_rpc.py", line 139, in prepare_devices_filter
    self._apply_port_filter(device_ids)
  File "/opt/stack/neutron/neutron/agent/securitygroups_rpc.py", line 164, in _apply_port_filter
    self.firewall.prepare_port_filter(device)
  File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
    self.gen.next()
  File "/opt/stack/neutron/neutron/agent/firewall.py", line 139, in defer_apply
    self.filter_defer_apply_off()
  File "/opt/stack/neutron/neutron/agent/linux/iptables_firewall.py", line 838, in filter_defer_apply_off
    self._pre_defer_unfiltered_ports)
  File "/opt/stack/neutron/neutron/agent/linux/iptables_firewall.py", line 248, in _remove_chains_apply
    self._remove_chain_by_name_v4v6(SG_CHAIN)
  File "/opt/stack/neutron/neutron/agent/linux/iptables_firewall.py", line 279, in _remove_chain_by_name_v4v6
    self.iptables.ipv4['filter'].remove_chain(chain_name)
  File "/opt/stack/neutron/neutron/agent/linux/iptables_manager.py", line 178, in remove_chain
    traceback.print_stack()

Looking at the code, there's a couple of things that are interesting:

1) prepare_port_filter() calls self._remove_chains() - why?
2) in the "defer" case above we always do _remove_chains_apply()/_setup_chains_apply() - is there some way to skip the remove?

This also led to us timing how long it's taking in the remove_chain()
code, since that's where the message is getting printed.  As the number
of ports and rules grow, it's spending more time spinning through chains
and rules.  It looks like that can be helped with a small code change,
which is just fallout from the real problem.  I'll send that out since
it helps a little.

More work still required.

** Affects: neutron
     Importance: Undecided
     Assignee: Brian Haley (brian-haley)
         Status: New

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to neutron.
https://bugs.launchpad.net/bugs/1642770

Title:
  Security group code is doing unnecessary work removing chains

Status in neutron:
  New

Bug description:
  The security group code is generating a lot of these messages when
  trying to boot VMs:

  Attempted to remove chain sg-chain which does not exist

  There's also ones specific to the port.  It seems to be calling
  remove_chain(), even when it's a new port and it's initially setting
  up it's filter.  I dropped a print_stack() in remove_chain() and see
  tracebacks like this:

  Prepare port filter for e8f41910-c24e-41f1-ae7f-355e9bb1d18a _apply_port_filter /opt/stack/neutron/neutron/agent/securitygroups_rpc.py:163
  Preparing device (e8f41910-c24e-41f1-ae7f-355e9bb1d18a) filter prepare_port_filter /opt/stack/neutron/neutron/agent/linux/iptables_firewall.py:170
  Attempted to remove chain sg-chain which does not exist remove_chain /opt/stack/neutron/neutron/agent/linux/iptables_manager.py:177
    File "/usr/local/lib/python2.7/dist-packages/eventlet/greenthread.py", line 214, in main
      result = function(*args, **kwargs)
    File "/usr/local/lib/python2.7/dist-packages/ryu/lib/hub.py", line 54, in _launch
      return func(*args, **kwargs)
    File "/opt/stack/neutron/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/ovs_ryuapp.py", line 37, in agent_main_wrapper
      ovs_agent.main(bridge_classes)
    File "/opt/stack/neutron/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py", line 2177, in main
      agent.daemon_loop()
    File "/usr/local/lib/python2.7/dist-packages/osprofiler/profiler.py", line 154, in wrapper
      return f(*args, **kwargs)
    File "/opt/stack/neutron/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py", line 2098, in daemon_loop
      self.rpc_loop(polling_manager=pm)
    File "/usr/local/lib/python2.7/dist-packages/osprofiler/profiler.py", line 154, in wrapper
      return f(*args, **kwargs)
    File "/opt/stack/neutron/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py", line 2049, in rpc_loop
      port_info, ovs_restarted)
    File "/usr/local/lib/python2.7/dist-packages/osprofiler/profiler.py", line 154, in wrapper
      return f(*args, **kwargs)
    File "/opt/stack/neutron/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py", line 1657, in process_network_ports
      port_info.get('updated', set()))
    File "/opt/stack/neutron/neutron/agent/securitygroups_rpc.py", line 266, in setup_port_filters
      self.prepare_devices_filter(new_devices)
    File "/opt/stack/neutron/neutron/agent/securitygroups_rpc.py", line 131, in decorated_function
      *args, **kwargs)
    File "/opt/stack/neutron/neutron/agent/securitygroups_rpc.py", line 139, in prepare_devices_filter
      self._apply_port_filter(device_ids)
    File "/opt/stack/neutron/neutron/agent/securitygroups_rpc.py", line 164, in _apply_port_filter
      self.firewall.prepare_port_filter(device)
    File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
      self.gen.next()
    File "/opt/stack/neutron/neutron/agent/firewall.py", line 139, in defer_apply
      self.filter_defer_apply_off()
    File "/opt/stack/neutron/neutron/agent/linux/iptables_firewall.py", line 838, in filter_defer_apply_off
      self._pre_defer_unfiltered_ports)
    File "/opt/stack/neutron/neutron/agent/linux/iptables_firewall.py", line 248, in _remove_chains_apply
      self._remove_chain_by_name_v4v6(SG_CHAIN)
    File "/opt/stack/neutron/neutron/agent/linux/iptables_firewall.py", line 279, in _remove_chain_by_name_v4v6
      self.iptables.ipv4['filter'].remove_chain(chain_name)
    File "/opt/stack/neutron/neutron/agent/linux/iptables_manager.py", line 178, in remove_chain
      traceback.print_stack()

  Looking at the code, there's a couple of things that are interesting:

  1) prepare_port_filter() calls self._remove_chains() - why?
  2) in the "defer" case above we always do _remove_chains_apply()/_setup_chains_apply() - is there some way to skip the remove?

  This also led to us timing how long it's taking in the remove_chain()
  code, since that's where the message is getting printed.  As the
  number of ports and rules grow, it's spending more time spinning
  through chains and rules.  It looks like that can be helped with a
  small code change, which is just fallout from the real problem.  I'll
  send that out since it helps a little.

  More work still required.

To manage notifications about this bug go to:
https://bugs.launchpad.net/neutron/+bug/1642770/+subscriptions