OVS driver unit tests random failure: "AssertionError: Mismatched values: 'source_ip_prefix', expected: u'10.0.0.9', actual: u'10.0.0.10'"

[Bernard Cafarelli]

Probably introduced in https://git.openstack.org/cgit/openstack/networking-sfc/commit/?id=ea5b9435d1a83e8242250b6a88e06401fe07e9ed

Depending on the IP addresses allocated, the unit tests can fail (expecting the wrong IP address).

Example:
networking_sfc.tests.unit.services.sfc.drivers.ovs.test_driver.OVSSfcDriverTestCase.test_agent_init_multi_flow_classifiers_port_pairs
-------------------------------------------------------------------------------------------------------------------------------------

Captured traceback:
~~~~~~~~~~~~~~~~~~~
    Traceback (most recent call last):
      File "/home/vagrant/networking-sfc/.tox/py27/src/neutron/neutron/tests/base.py", line 116, in func
        return f(self, *args, **kwargs)
      File "networking_sfc/tests/unit/services/sfc/drivers/ovs/test_driver.py", line 4248, in test_agent_init_multi_flow_classifiers_port_pairs
        }, add_fcs[0])
      File "/home/vagrant/networking-sfc/.tox/py27/lib/python2.7/site-packages/unittest2/case.py", line 1154, in assertDictContainsSubset
        self.fail(self._formatMessage(msg, standardMsg))
      File "/home/vagrant/networking-sfc/.tox/py27/lib/python2.7/site-packages/unittest2/case.py", line 690, in fail
        raise self.failureException(msg)
    AssertionError: Mismatched values: 'source_ip_prefix', expected: u'10.0.0.9', actual: u'10.0.0.10'

Checking this single test, I can get a failure about 50% of the time

[Fred S (fsbiz)]

Do all other tests pass ?
Only this one fails ?

[Bernard Cafarelli (bcafarel)]

Good point, there was test_create_port_chain_with_multi_fcs_port_pairs_with_symmetric in https://review.openstack.org/#/c/435835/:
http://logs.openstack.org/35/435835/1/check/gate-networking-sfc-python27-ubuntu-xenial/0173761/console.html
http://logs.openstack.org/35/435835/1/check/gate-networking-sfc-python35/f4e46ac/console.html

But it looks ok after a few runs with the latest patchset (that was committed), so yes it may be this single test

[Fred S (fsbiz)]

Looks ok to me. And all the unit tests are passing for me.
Are you still able to reproduce it?

[Bernard Cafarelli (bcafarel)]

Yes for test_agent_init_multi_flow_classifiers_port_pairs (I cannot run too many loops at the moment as I am away), it still happens with a clean env. Also I forgot to link the initial failures in RDO:
https://trunk.rdoproject.org/centos7-master-head/10/ce/10ceb5c62f8c8aa3449e6089167d33915430cdf1_6f0587ae/build.log
https://trunk.rdoproject.org/centos7/04/52/04524575c59f549e5d111a356e90df2a6a32ad1f_6f0587ae/build.log

[Bernard Cafarelli (bcafarel)]

And another one: https://trunk.rdoproject.org/centos7-master/10/ce/10ceb5c62f8c8aa3449e6089167d33915430cdf1_6f0587ae/rpmbuild.log

[Fred S (fsbiz)]

Is this a brand new tree with no code changes?
I see several messages like these in the logs.

Farhad.

DEBUG: File "/builddir/build/BUILD/networking-sfc-3.0.1.dev122/networking_sfc/services/flowclassifier/driver_manager.py", line 104, in _call_drivers
DEBUG: getattr(driver.obj, method_name)(context)
DEBUG: File "/usr/lib/python2.7/site-packages/mock/mock.py", line 1062, in __call__
DEBUG: return _mock_self._mock_call(*args, **kwargs)
DEBUG: File "/usr/lib/python2.7/site-packages/mock/mock.py", line 1118, in _mock_call
DEBUG: raise effect
DEBUG: FlowClassifierException: An unknown exception occurred.
DEBUG: Flow Classifier driver 'mock_driver' failed in update_flow_classifier_postcommit
DEBUG: An unknown exception occurred.
DEBUG: Traceback (most recent call last):
DEBUG: File "/builddir/build/BUILD/networking-sfc-3.0.1.dev122/networking_sfc/services/flowclassifier/driver_manager.py", line 104, in _call_drivers
DEBUG: getattr(driver.obj, method_name)(context)
DEBUG: File "/usr/lib/python2.7/site-packages/mock/mock.py", line 1062, in __call__
DEBUG: return _mock_self._mock_call(*args, **kwargs)
DEBUG: File "/usr/lib/python2.7/site-packages/mock/mock.py", line 1118, in _mock_call
DEBUG: raise effect
DEBUG: FlowClassifierException: An unknown exception occurred.
DEBUG: Flow Classifier driver 'mock_driver' failed in update_flow_classifier_precommit
DEBUG: An unknown exception occurred.
DEBUG: Traceback (most recent call last):
DEBUG: File "/builddir/build/BUILD/networking-sfc-3.0.1.dev122/networking_sfc/services/flowclassifier/driver_manager.py", line 104, in _call_drivers
DEBUG: getattr(driver.obj, method_name)(context)
DEBUG: File "/usr/lib/python2.7/site-packages/mock/mock.py", line 1062, in __call__
DEBUG: return _mock_self._mock_call(*args, **kwargs)
DEBUG: File "/usr/lib/python2.7/site-packages/mock/mock.py", line 1118, in _mock_call
DEBUG: raise effect

[Bernard Cafarelli (bcafarel)]

Yes, just a clean checkout of current master.

And on the Centos7 VM where I reproduce it, it is a new checkout (so with a just-built tox environment), just running "tox -e py27 networking_sfc.tests.unit.services.sfc.drivers.ovs.test_driver.OVSSfcDriverTestCase.test_agent_init_multi_flow_classifiers_port_pairs"

[Fred S (fsbiz)]

Can you back out my fix and try?
All tests are passing for everyone else and I am unable to reproduce it.
The following simple patch will back out my fix.
Can you please apply this patch and see if the test passes or fails?

Farhad

root@fs-10-145-106-2:/opt/stack/networking-sfc/networking_sfc/services/sfc/drivers/ovs# git diff
diff --git a/networking_sfc/services/sfc/drivers/ovs/driver.py b/networking_sfc/services/sfc/drivers/ovs/driver.py
index 6818363..9475d1f 100644
--- a/networking_sfc/services/sfc/drivers/ovs/driver.py
+++ b/networking_sfc/services/sfc/drivers/ovs/driver.py
@@ -610,6 +610,7 @@ class OVSSfcDriver(driver_base.SfcDriverBase,
             new_fc.pop('name')
             new_fc.pop('project_id')
             new_fc.pop('description')
+ """
             router_ints = const.ROUTER_INTERFACE_OWNERS
             logical_source_port = new_fc['logical_source_port']
             if logical_source_port is not None:
@@ -641,6 +642,7 @@ class OVSSfcDriver(driver_base.SfcDriverBase,
                         new_fc['destination_ip_prefix'] = (
                             dst_ips[0]['ip_address']
                         )
+ """

             if flow_rule['fwd_path'] is False:
                 # swap logcial_source_port & logical_destination_port

[Bernard Cafarelli (bcafarel)]

Yes it passes with this revert and reverting the 'source_ip_prefix' asserts to None.

So can this be distro-specific? Most elements would come from pip, so you should get the failure too. The test system is just:
* install centos 7, pip and tox
* git clone https://github.com/openstack/networking-sfc.git
* tox -e py27 networking_sfc.tests.unit.services.sfc.drivers.ovs.test_driver.OVSSfcDriverTestCase.test_agent_init_multi_flow_classifiers_port_pairs

Hope to find some time to look into it

[Bernard Cafarelli (bcafarel)]

OK, the bug is in the test, multiple fcs are stored in a list. So the failure I get is when the first fc actually has ip_src2 (there are a few tests that potentially can have the same problem).

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/456602

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/456602
Committed: https://git.openstack.org/cgit/openstack/networking-sfc/commit/?id=c28f7a38bd18d285392a97bb1730d63ef3f19d36
Submitter: Jenkins
Branch: master

commit c28f7a38bd18d285392a97bb1730d63ef3f19d36
Author: Bernard Cafarelli <email address hidden>
Date: Thu Apr 13 14:50:47 2017 +0200

    Fix UT failures with multiple flow classifiers

    Only observed on CentOS, but could happen on other systems:
     AssertionError: Mismatched values: 'source_ip_prefix',
     expected: u'10.0.0.9', actual: u'10.0.0.10

    The list of flow classifiers can be in a different order than the
    creation one, which causes the mismatch.

    These tests now sort (on a relevant key) flow classifiers and expected
    values lists. The assert check was also rewritten from the deprecated
    assertDictContainsSubset method, and works fine on python 2 and 3

    Change-Id: I5d7a6b4902522926ec07d06c8a291c5f41adc5bf
    Closes-Bug: #1666568

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/ocata
Review: https://review.openstack.org/456771

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/456771
Committed: https://git.openstack.org/cgit/openstack/networking-sfc/commit/?id=74b77540db67f4190aed248916daa8f612cd1460
Submitter: Jenkins
Branch: stable/ocata

commit 74b77540db67f4190aed248916daa8f612cd1460
Author: Bernard Cafarelli <email address hidden>
Date: Thu Apr 13 14:50:47 2017 +0200

    Fix UT failures with multiple flow classifiers

    Only observed on CentOS, but could happen on other systems:
     AssertionError: Mismatched values: 'source_ip_prefix',
     expected: u'10.0.0.9', actual: u'10.0.0.10

    The list of flow classifiers can be in a different order than the
    creation one, which causes the mismatch.

    These tests now sort (on a relevant key) flow classifiers and expected
    values lists. The assert check was also rewritten from the deprecated
    assertDictContainsSubset method, and works fine on python 2 and 3

    Change-Id: I5d7a6b4902522926ec07d06c8a291c5f41adc5bf
    Closes-Bug: #1666568
    (cherry picked from commit c28f7a38bd18d285392a97bb1730d63ef3f19d36)

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/networking-sfc 5.0.0.0b2 development milestone.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/networking-sfc ocata-eol release.