Remove extraneous trace in linux/dhcp.py

Bug #1414218 reported by Billy Olsen on 2015-01-23
12
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Ubuntu Cloud Archive
Undecided
Unassigned
Icehouse
Undecided
Unassigned
neutron
Undecided
Billy Olsen
Juno
Undecided
Stephen Ma
neutron (Ubuntu)
Low
Billy Olsen
Trusty
Low
Unassigned

Bug Description

[Impact]

The debug tracepoint in Dnsmasq._output_hosts_file is extraneous and causes unnecessary performance overhead when creating lots (> 1000) ports at one time.

The trace point is unnecessary since the data is being written to disk and the file can be examined in a worst case scenario. The added performance overhead is an order of magnitude in difference (~.5 seconds versus ~.05 seconds at 1500 ports).

[Test Case]

1. Deploy OpenStack using neutron for networking
2. Create 1500 ports
3. Observe the performance degradation for each port creation.

[Regression Potential]

Minimal. This code has been running in stable/juno, stable/kilo, and above for awhile.

[Other Questions]

This is likely to occur in OpenStack deployments which have large networks deployed. The degradation is gradual, but the performance becomes unacceptable with large enough networks.

Changed in neutron:
assignee: nobody → Billy Olsen (billy-olsen)
status: New → In Progress

Reviewed: https://review.openstack.org/149784
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=d93e0098ebd5f333d6f496f10a663cd4351410ae
Submitter: Jenkins
Branch: master

commit d93e0098ebd5f333d6f496f10a663cd4351410ae
Author: Billy Olsen <email address hidden>
Date: Fri Jan 23 15:50:40 2015 -0700

    Refactor logging in loop to only log debug messages once

    Logging entries in a loop to a file can be expensive for a large
    number of objects (e.g. ports) in a loop. Rather than perform the
    overhead of logging a debug entry for each line within the hosts
    file, move the debug trace of the contents to after the loop to
    bulk up the I/O operations.

    Change-Id: I3ad7864eeb2f959549ed356a1e34fa18804395cc
    Closes-Bug: #1414218

Changed in neutron:
status: In Progress → Fix Committed
Thierry Carrez (ttx) on 2015-03-19
Changed in neutron:
milestone: none → kilo-3
status: Fix Committed → Fix Released

Reviewed: https://review.openstack.org/164329
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=70786c65773ca4e4bc8875842e733a0bcabd4ed4
Submitter: Jenkins
Branch: stable/juno

commit 70786c65773ca4e4bc8875842e733a0bcabd4ed4
Author: Billy Olsen <email address hidden>
Date: Fri Jan 23 15:50:40 2015 -0700

    Refactor logging in loop to only log debug messages once

    Logging entries in a loop to a file can be expensive for a large
    number of objects (e.g. ports) in a loop. Rather than perform the
    overhead of logging a debug entry for each line within the hosts
    file, move the debug trace of the contents to after the loop to
    bulk up the I/O operations.

    Conflicts:
            neutron/agent/linux/dhcp.py

    (cherry-picked from d93e0098ebd5f333d6f496f10a663cd4351410ae)
    Change-Id: I3ad7864eeb2f959549ed356a1e34fa18804395cc
    Closes-Bug: #1414218

tags: added: in-stable-juno

Related fix proposed to branch: master
Review: https://review.openstack.org/175445

Reviewed: https://review.openstack.org/175445
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=3b74095a935f6d2027e6bf04cc4aa21f8a1b46f2
Submitter: Jenkins
Branch: master

commit 3b74095a935f6d2027e6bf04cc4aa21f8a1b46f2
Author: Ihar Hrachyshka <email address hidden>
Date: Mon Apr 20 17:06:38 2015 +0200

    tests: confirm that _output_hosts_file does not log too often

    I3ad7864eeb2f959549ed356a1e34fa18804395cc didn't include any regression unit
    tests to validate that the method won't ever log too often again,
    reintroducing performance drop in later patches. It didn't play well
    with stable backports of the fix, where context was lost when doing the
    backport, that left the bug unfixed in stable/juno even though the patch
    was merged there [1].

    The patch adds an explicit note in the code that suggests not to add new
    log messages inside the loop to avoid regression, and a unit test was
    added to capture it.

    Once the test is merged in master, it will be proposed for stable/juno
    inclusion, with additional changes that would fix the regression again.

    Related-Bug: #1414218
    Change-Id: I5d43021932d6a994638c348eda277dd8337cf041

Reviewed: https://review.openstack.org/176672
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=38211ae67cb76ade85b08c028b6e88bfc867afc9
Submitter: Jenkins
Branch: stable/kilo

commit 38211ae67cb76ade85b08c028b6e88bfc867afc9
Author: Ihar Hrachyshka <email address hidden>
Date: Mon Apr 20 17:06:38 2015 +0200

    tests: confirm that _output_hosts_file does not log too often

    I3ad7864eeb2f959549ed356a1e34fa18804395cc didn't include any regression unit
    tests to validate that the method won't ever log too often again,
    reintroducing performance drop in later patches. It didn't play well
    with stable backports of the fix, where context was lost when doing the
    backport, that left the bug unfixed in stable/juno even though the patch
    was merged there [1].

    The patch adds an explicit note in the code that suggests not to add new
    log messages inside the loop to avoid regression, and a unit test was
    added to capture it.

    Once the test is merged in master, it will be proposed for stable/juno
    inclusion, with additional changes that would fix the regression again.

    Related-Bug: #1414218
    Change-Id: I5d43021932d6a994638c348eda277dd8337cf041
    (cherry picked from commit 3b74095a935f6d2027e6bf04cc4aa21f8a1b46f2)

tags: added: in-stable-kilo

Reviewed: https://review.openstack.org/176679
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=59b9735af1b4004c5877c5f87ccae114c63f06e0
Submitter: Jenkins
Branch: stable/juno

commit 59b9735af1b4004c5877c5f87ccae114c63f06e0
Author: Ihar Hrachyshka <email address hidden>
Date: Mon Apr 20 17:06:38 2015 +0200

    tests: confirm that _output_hosts_file does not log too often

    I3ad7864eeb2f959549ed356a1e34fa18804395cc didn't include any regression unit
    tests to validate that the method won't ever log too often again,
    reintroducing performance drop in later patches. It didn't play well
    with stable backports of the fix, where context was lost when doing the
    backport, that left the bug unfixed in stable/juno even though the patch
    was merged there [1].

    The patch adds an explicit note in the code that suggests not to add new
    log messages inside the loop to avoid regression, and a unit test was
    added to capture it.

    Once the test is merged in master, it will be proposed for stable/juno
    inclusion, with additional changes that would fix the regression again.

    Conflicts:
     neutron/agent/linux/dhcp.py
     neutron/tests/unit/test_linux_dhcp.py

    Local changes:
    - remove LOG.debug messages that sneaked into the for loop with a
      backport.

    Related-Bug: #1414218
    Change-Id: I5d43021932d6a994638c348eda277dd8337cf041
    (cherry picked from commit 3b74095a935f6d2027e6bf04cc4aa21f8a1b46f2)

Thierry Carrez (ttx) on 2015-04-30
Changed in neutron:
milestone: kilo-3 → 2015.1.0

Change abandoned by stephen-ma (<email address hidden>) on branch: master
Review: https://review.openstack.org/175061
Reason: The unit test has been added in Change-Id I5d43021932d6a994638c348eda277dd8337cf041.

Change abandoned by stephen-ma (<email address hidden>) on branch: stable/juno
Review: https://review.openstack.org/174596

Download full text (11.7 KiB)

Reviewed: https://review.openstack.org/179286
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=b8a09568b5bde8b71ad00468c27b757c98d9c0da
Submitter: Jenkins
Branch: master

commit 7260e0e3fc2ea479e80e0962624aca7fd38a1f60
Author: Henry Gessau <email address hidden>
Date: Mon Apr 27 09:59:21 2015 -0400

    Run radvd as root

    During the refactoring of external process management radvd lost
    its root privileges.

    Closes-bug: 1448813

    Change-Id: I84883fe81684afafac9b024282a03f447c8f825a
    (cherry picked from commit a5e54338770fc074e01fa88dbf909ee1af1b66b2)

commit d37e566dcadf8a540eb5f84b668847fa192393a1
Author: Kevin Benton <email address hidden>
Date: Fri Apr 24 00:35:31 2015 -0700

    Don't resync on DHCP agent setup failure

    There are various cases where the DHCP agent will try to
    create a DHCP port for a network and there will be a failure.
    This has primarily been caused by a lack of available IP addresses
    in the allocation pool. Trying to fix all availability corner cases
    on the server side will be very difficult due to race conditions between
    multiple ports being created, the dhcp_agents_per_network parameter, etc.

    This patch just stops the resync attempt on the agent side if a failure
    is caused by an IP address generation problem. Future updates to the subnet
    will cause another attempt so if the tenant does fix the issue they will
    get DHCP service.

    Change-Id: I0896730126d6dca13fe9284b4d812cfb081b6218
    Closes-Bug: #1447883
    (cherry picked from commit db9ac7e0110a0c2ef1b65213317ee8b7f1053ddc)

commit 38211ae67cb76ade85b08c028b6e88bfc867afc9
Author: Ihar Hrachyshka <email address hidden>
Date: Mon Apr 20 17:06:38 2015 +0200

    tests: confirm that _output_hosts_file does not log too often

    I3ad7864eeb2f959549ed356a1e34fa18804395cc didn't include any regression unit
    tests to validate that the method won't ever log too often again,
    reintroducing performance drop in later patches. It didn't play well
    with stable backports of the fix, where context was lost when doing the
    backport, that left the bug unfixed in stable/juno even though the patch
    was merged there [1].

    The patch adds an explicit note in the code that suggests not to add new
    log messages inside the loop to avoid regression, and a unit test was
    added to capture it.

    Once the test is merged in master, it will be proposed for stable/juno
    inclusion, with additional changes that would fix the regression again.

    Related-Bug: #1414218
    Change-Id: I5d43021932d6a994638c348eda277dd8337cf041
    (cherry picked from commit 3b74095a935f6d2027e6bf04cc4aa21f8a1b46f2)

commit 53b3e751f3c7b32bed48c14742d3dd3a1178d00d
Author: Maru Newby <email address hidden>
Date: Thu Apr 9 17:00:57 2015 +0000

    Double functional testing timeout to 180s

    The increase in ovs testing is resulting in job failure due to
    timeouts in test_killed_monitor_respawns. Giving the test more
    time to complete should reduce the failure rate.

    Change-Id: I2ba9b1eb388bfbbebbd6b0f3edb6d5a5ae0bfead
    Closes-Bug: #1442272
    (c...

Download full text (93.9 KiB)

Reviewed: https://review.openstack.org/196097
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=1cfed745d54a6ce9cb3dd4e6f454666d9e6676c2
Submitter: Jenkins
Branch: feature/qos

commit ba7d673d1ddd5bfa5aa1be5b26a59e9a8cd78a9f
Author: Kevin Benton <email address hidden>
Date: Thu Jun 25 18:31:38 2015 -0700

    Remove duplicated call to setup_coreplugin

    The test case for vlan_transparent was calling setup_coreplugin
    before calling the super setUp method which already calls
    setup_coreplugin. This was causing duplicate core plugin fixtures
    which resulted in patching the dhcp periodic check twice.

    Change-Id: Ide4efad42748e799d8e9c815480c8ffa94b27b38
    Partial-Bug: #1468998

commit e64062efa3b793f7c4ce4ab9e62918af4f1bfcc9
Author: Kevin Benton <email address hidden>
Date: Thu Jun 25 18:29:37 2015 -0700

    Remove double mock of dhcp agent periodic check

    The test case for the periodic check was patching a target
    that the core plugin fixture already patched out. This removes
    that and exposes the mock from the fixture so the test case
    can reference it.

    Change-Id: I3adee6a875c497e070db4198567b52aa16b81ce8
    Partial-Bug: #1468998

commit 25ae0429a713143d42f626dd59ed4514ba25820c
Author: Kevin Benton <email address hidden>
Date: Thu Jun 25 18:24:10 2015 -0700

    Remove double fanout mock

    The test_mech_driver was duplicating a fanout mock already setup
    in the setUp routine.

    Change-Id: I5b88dff13113d55c72241d3d5025791a76672ac2
    Partial-Bug: #1468998

commit 993771556332d9b6bbf7eb3f0300cf9d8a2cb464
Author: Kevin Benton <email address hidden>
Date: Thu Jun 25 17:55:16 2015 -0700

    Remove double callback manager mocks

    setup_test_registry_instance() in the base test case class gives
    each test its own registry by mocking out the get_callback_manager.
    The L3 agent test cases were duplicating this.

    Partial-Bug: #1468998
    Change-Id: I7356daa846524611e9f92365939e8ad15d1e1cd8

commit 0be1efad93734f11cd63fb3b7bd2983442ce1268
Author: Kevin Benton <email address hidden>
Date: Thu Jun 25 16:57:30 2015 -0700

    Remove ensure_dirs double-patch

    test_spawn_radvd called mock.patch on ensure_dirs after the
    setup method already patched it out. This causes issues when
    mock.patch.stopall() is called because the mocks are stored
    as a set and are unwound in a non-deterministic fashion.[1]
    So some of the time they will be undone correctly, but others
    will leave a monkey-patched in mock, causing the ensure_dir
    test to fail.

    1. http://bugs.python.org/issue21239

    Closes-Bug: #1467908
    Change-Id: I321b5fed71dc73bd19b5099311c6f43640726cd4

commit 0a2238e34e72c17ca8a75e36b1f56e41a3ece74e
Author: Sukhdev Kapur <email address hidden>
Date: Thu Jun 25 15:11:28 2015 -0700

    Fix tenant-id in Arista ML2 driver to support HA router

    When HA router is created, the framework creates a network and does
    not specify the tenant-id. This casuse Arista ML2 driver to fail.
    This patch sets the tenant-id when it is not passed explicitly by
    by the network_create() call from the HA r...

tags: added: in-feature-qos

Change abandoned by Kyle Mestery (<email address hidden>) on branch: feature/pecan
Review: https://review.openstack.org/196701
Reason: This is lacking the functional fix [1], so I'll propose a new merge commit which includes that one.

[1] https://review.openstack.org/#/c/196711/

Download full text (171.5 KiB)

Reviewed: https://review.openstack.org/196920
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=7f759c077f8f860c13db92d2ea6b353ef6b70900
Submitter: Jenkins
Branch: feature/pecan

commit 8123144fadd7c5d5e6e56a76ea860512619a2cf6
Author: Moshe Levi <email address hidden>
Date: Sun Jun 28 14:37:14 2015 +0300

    Fix Consolidate sriov agent and driver code

    This patch add mising __init to mech_sriov/mech_driver/
    and update the setup.cfg to the new agent entrypoint

    Trivial Fix

    Change-Id: I53a527081feb78472f496675bbb3c5121d38a14a

commit 8942fccf02e6e179d47582fdb2792a1ca972da21
Author: Assaf Muller <email address hidden>
Date: Mon Jun 29 11:38:51 2015 -0400

    Remove failing SafeFixture tests

    The fixtures 1.3 release attempted to fix the fixtures resource
    leak issue, but failed to do so completely. Our own SafeFixture
    is still needed: The 1.3 release broke our SafeFixture tests,
    but not the usage of SafeFixture itself. This patch removes
    those failing tests for now to unbreak the gate. Jakub reported
    a bug on fixtures 1.3:
    https://bugs.launchpad.net/python-fixtures/+bug/1469759

    We will continue to use SafeFixture until that bug is fixed
    in fixtures, at which point we will be able to require
    fixtures > 1.3.

    Change-Id: I59457c3bb198ff86d5ad55a1e623d008f0034b8f
    Closes-Bug: #1469734

commit 71dffb0a2c1720cd8233a329d32958a0160dd6f5
Author: Kevin Benton <email address hidden>
Date: Mon Jun 29 08:27:41 2015 +0000

    Revert "Removed test_lib module"

    This reverts commit 9a6536de6e1a7fe9b2552adc142e254426b82b6f.

    We pulled all of the plugins out of the tree, many of which still inherit
    from neutron test classes. This change then stated that we no longer
    support testing other plugins. I think this is a bit premature and should
    have been discussed under the subject
    "Neutron plugins can't use neutron plugin unit tests" or something
    similar.

    Change-Id: I68318589f010b731574ea3bfa8df98492bab31fc

commit b20fd81dbd497e058384a0af065dd0f1fdc4c728
Author: Jakub Libosvar <email address hidden>
Date: Fri Jun 5 14:32:51 2015 +0000

    Refactor NetcatTester class

    Following capabilities were added:
       - used transport protocol is passed as a constant instead of bool
       - src port for testing was added
       - connection can be established explicitly
       - change constructor parameters of NetcatTester

    As a part of removing bool for protocol definition
    get_free_namespace_port() was also modified to match the behavior.

    Change-Id: Id2ec322e7f731c05a3754a65411c9a5d8b258126

commit 83e37980dcd0b2bad6d64dd2cb23bcd2891cafca
Author: jingliuqing <email address hidden>
Date: Sat Jun 27 13:41:54 2015 +0800

    Use REST rather than ReST

    Change-Id: I06c9deaab58c5ec13bfeec39fb8fd4b1fe21f42d

commit 1b60df85ba3ad442c2e4e7e52538e1b9a1bf9378
Author: Kevin Benton <email address hidden>
Date: Thu Jun 25 18:34:38 2015 -0700

    Add a double-mock guard to the base test case

    Use mock to patch mock with a check to prevent multiple active
    patches to the...

tags: added: in-feature-pecan
description: updated
Billy Olsen (billy-olsen) wrote :

This patch only applies to Trusty. It has already been fixed in Juno+ upstream, but needs to be fixed in Trusty for large scale scenarios.

Dave Chiluk (chiluk) on 2016-07-05
Changed in neutron (Ubuntu):
assignee: nobody → Billy Olsen (billy-olsen)
Changed in cloud-archive:
status: New → Confirmed
Changed in neutron (Ubuntu):
importance: Undecided → Low

I've uploaded the patch to the trusty-proposed queue. Not sure how to handle the cloud-archive stuff!

Changed in neutron (Ubuntu):
status: New → Fix Released
Changed in neutron (Ubuntu Trusty):
status: New → In Progress
Changed in neutron (Ubuntu Trusty):
importance: Undecided → Low

Hello Billy, or anyone else affected,

Accepted neutron into trusty-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/neutron/1:2014.1.5-0ubuntu5 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, and change the tag from verification-needed to verification-done. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

Changed in neutron (Ubuntu Trusty):
status: In Progress → Fix Committed
tags: added: verification-needed
Billy Olsen (billy-olsen) wrote :

Verification confirmed.

tags: added: verification-done
removed: verification-needed

The verification of the Stable Release Update for neutron has completed successfully and the package has now been released to -updates. Subsequently, the Ubuntu Stable Release Updates Team is being unsubscribed and will not receive messages about this bug report. In the event that you encounter a regression using the package from -updates please report a new bug using ubuntu-bug and tag the bug report regression-update so we can easily find any regressions.

Launchpad Janitor (janitor) wrote :

This bug was fixed in the package neutron - 1:2014.1.5-0ubuntu5

---------------
neutron (1:2014.1.5-0ubuntu5) trusty; urgency=medium

  * Backport performance fix by refactoring logging statements. (LP: #1414218):
    - d/p/refactor-log-in-loop.patch: do not perform debug trace with each
      iteration through the loop of ports, instead log it once at the end.

 -- Billy Olsen <email address hidden> Tue, 05 Jul 2016 15:07:28 -0700

Changed in neutron (Ubuntu Trusty):
status: Fix Committed → Fix Released
Changed in cloud-archive:
status: Confirmed → Invalid
Ryan Beisner (1chb1n) wrote :

The verification of the Stable Release Update for neutron has completed successfully and the package has now been released to -updates. In the event that you encounter a regression using the package from -updates please report a new bug using ubuntu-bug and tag the bug report regression-update so we can easily find any regressions.

Ryan Beisner (1chb1n) wrote :

This bug was fixed in the package neutron - 1:2014.1.5-0ubuntu5~cloud0
---------------

 neutron (1:2014.1.5-0ubuntu5~cloud0) precise-icehouse; urgency=medium
 .
   * New update for the Ubuntu Cloud Archive.
 .
 neutron (1:2014.1.5-0ubuntu5) trusty; urgency=medium
 .
   * Backport performance fix by refactoring logging statements. (LP: #1414218):
     - d/p/refactor-log-in-loop.patch: do not perform debug trace with each
       iteration through the loop of ports, instead log it once at the end.

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.