yahoo-eng-team team mailing list archive

[Rawlin Peters <rawlin.peters@xxxxxx>]

Public bug reported:

In ipset_manager, the use of the @utils.synchronized decorator causes
duplicated log info about lock acquisition/release. In iptables_manager,
there is more duplicated logging from the usage of lockutils.lock()
without passing do_log=False. Because external=True is passed, the lock
acquire/release is already logged from within the lock implementation
itself, rendering the extra logging unnecessary.

Use of synchronized decorator in ipset_manager:
https://github.com/openstack/neutron/blob/master/neutron/agent/linux/ipset_manager.py#L50
https://github.com/openstack/neutron/blob/master/neutron/agent/linux/ipset_manager.py#L78

Use of lockutils.lock() in iptables_manager, with extra logging:
https://github.com/openstack/neutron/blob/master/neutron/agent/linux/iptables_manager.py#L427

Logging in lockutils.synchronized(), which uses lockutils.lock():
https://github.com/openstack/oslo.concurrency/blob/master/oslo_concurrency/lockutils.py#L247
https://github.com/openstack/oslo.concurrency/blob/master/oslo_concurrency/lockutils.py#L259

Logging in lockutils.lock():
https://github.com/openstack/oslo.concurrency/blob/master/oslo_concurrency/lockutils.py#L196
https://github.com/openstack/oslo.concurrency/blob/master/oslo_concurrency/lockutils.py#L209

Logging in the fasteners module, now used by lockutils for interprocess locking:
https://github.com/harlowja/fasteners/blob/master/fasteners/process_lock.py#L161
https://github.com/harlowja/fasteners/blob/master/fasteners/process_lock.py#L192

ipset_manager.set_members() is called once for every rule in a security
group when adding that security group to a server. With the current
logging, ipset_manager logs 4 lines about lock acquisition/release
because of using the @synchronized decorator. When adding a security
group with 50 rules to a server, 200 lines of output are appended to the
log file (of which 100 are duplicated info).

When iptables_manager.apply() is called, 6 lines of debug info (of which
4 are duplicated info) are logged per lock acquisition/release.

** Affects: neutron
     Importance: Undecided
         Status: New


** Tags: debug ipset ipset-manager iptables iptables-manager lock lockutils logging

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

Title:
  duplicated debug logging in ipset_manager and iptables_manager

Status in OpenStack Neutron (virtual network service):
  New

Bug description:
  In ipset_manager, the use of the @utils.synchronized decorator causes
  duplicated log info about lock acquisition/release. In
  iptables_manager, there is more duplicated logging from the usage of
  lockutils.lock() without passing do_log=False. Because external=True
  is passed, the lock acquire/release is already logged from within the
  lock implementation itself, rendering the extra logging unnecessary.

  Use of synchronized decorator in ipset_manager:
  https://github.com/openstack/neutron/blob/master/neutron/agent/linux/ipset_manager.py#L50
  https://github.com/openstack/neutron/blob/master/neutron/agent/linux/ipset_manager.py#L78

  Use of lockutils.lock() in iptables_manager, with extra logging:
  https://github.com/openstack/neutron/blob/master/neutron/agent/linux/iptables_manager.py#L427

  Logging in lockutils.synchronized(), which uses lockutils.lock():
  https://github.com/openstack/oslo.concurrency/blob/master/oslo_concurrency/lockutils.py#L247
  https://github.com/openstack/oslo.concurrency/blob/master/oslo_concurrency/lockutils.py#L259

  Logging in lockutils.lock():
  https://github.com/openstack/oslo.concurrency/blob/master/oslo_concurrency/lockutils.py#L196
  https://github.com/openstack/oslo.concurrency/blob/master/oslo_concurrency/lockutils.py#L209

  Logging in the fasteners module, now used by lockutils for interprocess locking:
  https://github.com/harlowja/fasteners/blob/master/fasteners/process_lock.py#L161
  https://github.com/harlowja/fasteners/blob/master/fasteners/process_lock.py#L192

  ipset_manager.set_members() is called once for every rule in a
  security group when adding that security group to a server. With the
  current logging, ipset_manager logs 4 lines about lock
  acquisition/release because of using the @synchronized decorator. When
  adding a security group with 50 rules to a server, 200 lines of output
  are appended to the log file (of which 100 are duplicated info).

  When iptables_manager.apply() is called, 6 lines of debug info (of
  which 4 are duplicated info) are logged per lock acquisition/release.

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