fullstack neutron.tests.fullstack.test_qos.TestDscpMarkingQoSOvs.test_dscp_marking_packets(openflow-native) failure

[Slawek Kaplonski]

Fullstack neutron.tests.fullstack.test_qos.TestDscpMarkingQoSOvs.test_dscp_marking_packets(openflow-native) fails sometimes like on: http://logs.openstack.org/71/520371/7/check/legacy-neutron-dsvm-fullstack/ad585a2/logs/testr_results.html.gz

In neutron-server logs there are errors like:
http://logs.openstack.org/71/520371/7/check/legacy-neutron-dsvm-fullstack/ad585a2/logs/dsvm-fullstack-logs/TestDscpMarkingQoSOvs.test_dscp_marking_packets_openflow-native_/neutron-server--2017-11-20--22-12-38-673206.txt.gz?level=TRACE

in such case.

[Slawek Kaplonski (slaweq)]

It looks like this issue starts happening at 18.11.2017: http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22neutron.tests.common.agents.l2_extensions.TcpdumpException%3A%20No%20packets%20marked%20with%20DSCP%20%3D%2016%20received%20from%5C%22
There wasn't any single fail with such error message before this date.
I now need to check what could cause this issue then.

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/523517
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=f0f480b5e1dfb52961c58c3a94a3ab4c400ac82b
Submitter: Zuul
Branch: master

commit f0f480b5e1dfb52961c58c3a94a3ab4c400ac82b
Author: Ihar Hrachyshka <email address hidden>
Date: Tue Nov 28 11:58:18 2017 -0800

    Disable test_dscp_marking_packets fullstack test case

    We disable test cases that are known to fail in attempt to get the
    fullstack job pass and be able to make it voting.

    Change-Id: If44a758bc7e81277437373569c3a39332bcd9bde
    Related-Bug: #1733649

[Slawek Kaplonski (slaweq)]

I have troubles with reproduce it but I dig more into logs on one case when this test failed.
What I found is that it looks for me that sometimes notification about created qos rule is not send to L2 agent.
Please take a look at neutron server log: http://logs.openstack.org/51/396351/45/check/legacy-neutron-dsvm-fullstack/58503bb/logs/dsvm-fullstack-logs/TestDscpMarkingQoSOvs.test_dscp_marking_packets_openflow-cli_/neutron-server--2017-11-29--23-35-16-294858.txt.gz#_2017-11-29_23_36_06_246 - it looks that dscp_marking rule was created at 23:36:06 but first message about this rule in ovs agent log is at 23:36:21 and it is about deleting this rule: http://logs.openstack.org/51/396351/45/check/legacy-neutron-dsvm-fullstack/58503bb/logs/dsvm-fullstack-logs/TestDscpMarkingQoSOvs.test_dscp_marking_packets_openflow-cli_/neutron-openvswitch-agent--2017-11-29--23-35-38-268049.txt.gz#_2017-11-29_23_36_21_063
and second agent even later: http://logs.openstack.org/51/396351/45/check/legacy-neutron-dsvm-fullstack/58503bb/logs/dsvm-fullstack-logs/TestDscpMarkingQoSOvs.test_dscp_marking_packets_openflow-cli_/neutron-openvswitch-agent--2017-11-29--23-35-38-914674.txt.gz#_2017-11-29_23_35_57_136

[Slawek Kaplonski (slaweq)]

After more digging into logs it looks that everything on server and agent side is done properly. Openflow rules are configured by agent (there is no logging exactly what rule is set but it doesn't look like that could be an issue here).
My next suspect is output from tcpdump which maybe don't match regex properly and that's why test fails but I still have to check that.

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/525156
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=034934aaf9105cce31770cf89c816875f702df6c
Submitter: Zuul
Branch: master

commit 034934aaf9105cce31770cf89c816875f702df6c
Author: Sławek Kapłoński <email address hidden>
Date: Mon Dec 4 12:11:25 2017 +0100

    [Fullstack] Log tcpdump output lines in DSCP mark tests

    This patch adds additional logging of captured tcpdump output during
    dscp mark packets tests.

    Change-Id: I1ab5727ea70afbe19d2557b9b5c4d77500658cbc
    Related-Bug: #1733649

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/527341
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=7d5247bc4ce0ea4d4d171fb9abb792f5f826e964
Submitter: Zuul
Branch: master

commit 7d5247bc4ce0ea4d4d171fb9abb792f5f826e964
Author: Sławek Kapłoński <email address hidden>
Date: Tue Dec 12 09:35:17 2017 +0100

    [Fullstack] Additional log of tcpdump stderr output

    This patch adds additional logging of tcpdump stderr output in
    DSCP marking packets tests.
    It is required to figure out why those tests are failing sometimes.

    Change-Id: I02fe64bf817b47970e4e073f48ea8dea53bdd4f5
    Related-Bug: #1733649

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/530212
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=b841a7f5d9a54468945e7eccecc91428797ebba9
Submitter: Zuul
Branch: master

commit b841a7f5d9a54468945e7eccecc91428797ebba9
Author: Sławek Kapłoński <email address hidden>
Date: Wed Dec 27 11:49:44 2017 +0100

    [Fullstack] Shutdown tcpdump process gracefully

    In fullstack test for dscp marking packets tcpdump is used to capture
    packets send from one namespace (Fake VM) to another one.
    When tcpdump is closed quickly with SIGKILL signal it may not displays
    all packets and that might cause an issue with failed dscp marking test.

    Now tcpdump will be kill with SIGINT signal so it should display
    all captured packets to the stdout.
    Also it should now return to stderr summary of all captured/dropped
    packets which can be helpful in future debugging of issue with those
    tests if that will not solve the problem.

    Change-Id: Ib2d588d081a48f4f2b6e98a943bca95b9955a149
    Related-Bug: #1733649

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/531169
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=386ec26b3d24f5862f6f76e0124a4370f45080cf
Submitter: Zuul
Branch: master

commit 386ec26b3d24f5862f6f76e0124a4370f45080cf
Author: Sławek Kapłoński <email address hidden>
Date: Thu Jan 4 15:51:01 2018 +0100

    [Fullstack] Change how DSCP marking packets are tested

    In fullstack test test_dscp_marking_packets two fake hosts are
    created, each of them has got one fake instance (called sender and
    receiver).
    Instance called "sender" sends ICMP packets to instance called
    "receiver". In receiver's namespace tcpdump process is spawned with
    filter to match only packets marked with specified DSCP value.
    After sender instance successfully pings receiver, tcpdump process
    is killed and stdout from it was examined to search logged ICMP
    packets which were send from sender's IP to receiver's IP address.
    That check was failing sometimes as is described in bug report.

    It was failing when tcpdump doesn't capture any packets so there was
    nothing on stdout from it. But even in such case tcpdump reports on
    stderr summary of packets and it was like below:

    0 packets captured
    6 packets received by filter
    0 packets dropped by kernel

    which means that packets matching our filter was received by tcpdump but
    were probably not processed yet. See [1] for more details.

    So this patch changes filter used in tcpdump and way how its output is
    checked.
    Now in filter expression there are added src and dst IP addresses also so
    it will match only packets send from sender instance to receiver instance.
    After that tcpdump's stderr output is examined with regex to check if
    line like:

    X packets received by filter

    is there and if X value is different than 0. If so, it means that
    tcpdump received packets with wanted DSCP mark and test should pass.

    [1] https://unix.stackexchange.com/a/29369

    Change-Id: Ia3522237dc787edb90d162ac4a5535ff5d2a03d5
    Closes-Bug: #1733649

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/neutron 12.0.0.0b3 development milestone.

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Related fix proposed to branch: stable/pike
Review: https://review.openstack.org/540422

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/pike
Review: https://review.openstack.org/540423

[OpenStack Infra (hudson-openstack)]

Related fix proposed to branch: stable/ocata
Review: https://review.openstack.org/540457

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/539953
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=6407a71d06c81f937c21079fc54aa2709a223e20
Submitter: Zuul
Branch: master

commit 6407a71d06c81f937c21079fc54aa2709a223e20
Author: Sławek Kapłoński <email address hidden>
Date: Thu Feb 1 14:42:02 2018 +0100

    [Fullstack] Unmark test_dscp_marking_packets as unstable

    Bug 1733649 is now closed with patch
    Ia3522237dc787edb90d162ac4a5535ff5d2a03d5

    This commit removes decorator which marked fullstack test
    test_qos.TestDscpMarkingQoSOvs.test_dscp_marking_packets
    as unstable.

    This commit removes also some additional logs of tcpdump's
    output added only as temporary "debug" solution.

    Change-Id: I0343b1b4fd8d6eed1c26838bf70bce9868e6ee0c
    Related-Bug: #1733649

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/540422
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=a3678747ebb293955c4d2c56dfe52ec6932d0822
Submitter: Zuul
Branch: stable/pike

commit a3678747ebb293955c4d2c56dfe52ec6932d0822
Author: Sławek Kapłoński <email address hidden>
Date: Wed Dec 27 11:49:44 2017 +0100

    [Fullstack] Shutdown tcpdump process gracefully

    In fullstack test for dscp marking packets tcpdump is used to capture
    packets send from one namespace (Fake VM) to another one.
    When tcpdump is closed quickly with SIGKILL signal it may not displays
    all packets and that might cause an issue with failed dscp marking test.

    Now tcpdump will be kill with SIGINT signal so it should display
    all captured packets to the stdout.
    Also it should now return to stderr summary of all captured/dropped
    packets which can be helpful in future debugging of issue with those
    tests if that will not solve the problem.

    Change-Id: Ib2d588d081a48f4f2b6e98a943bca95b9955a149
    Related-Bug: #1733649
    (cherry picked from commit b841a7f5d9a54468945e7eccecc91428797ebba9)

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/540423
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=edd6e51be629f1f1b230eb4034069cbd1d58db92
Submitter: Zuul
Branch: stable/pike

commit edd6e51be629f1f1b230eb4034069cbd1d58db92
Author: Sławek Kapłoński <email address hidden>
Date: Thu Jan 4 15:51:01 2018 +0100

    [Fullstack] Change how DSCP marking packets are tested

    In fullstack test test_dscp_marking_packets two fake hosts are
    created, each of them has got one fake instance (called sender and
    receiver).
    Instance called "sender" sends ICMP packets to instance called
    "receiver". In receiver's namespace tcpdump process is spawned with
    filter to match only packets marked with specified DSCP value.
    After sender instance successfully pings receiver, tcpdump process
    is killed and stdout from it was examined to search logged ICMP
    packets which were send from sender's IP to receiver's IP address.
    That check was failing sometimes as is described in bug report.

    It was failing when tcpdump doesn't capture any packets so there was
    nothing on stdout from it. But even in such case tcpdump reports on
    stderr summary of packets and it was like below:

    0 packets captured
    6 packets received by filter
    0 packets dropped by kernel

    which means that packets matching our filter was received by tcpdump but
    were probably not processed yet. See [1] for more details.

    So this patch changes filter used in tcpdump and way how its output is
    checked.
    Now in filter expression there are added src and dst IP addresses also so
    it will match only packets send from sender instance to receiver instance.
    After that tcpdump's stderr output is examined with regex to check if
    line like:

    X packets received by filter

    is there and if X value is different than 0. If so, it means that
    tcpdump received packets with wanted DSCP mark and test should pass.

    [1] https://unix.stackexchange.com/a/29369

    Change-Id: Ia3522237dc787edb90d162ac4a5535ff5d2a03d5
    Closes-Bug: #1733649
    (cherry picked from commit 386ec26b3d24f5862f6f76e0124a4370f45080cf)

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/540457
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=5ba8e4686d87758cf931dcf587963abc82a95e54
Submitter: Zuul
Branch: stable/ocata

commit 5ba8e4686d87758cf931dcf587963abc82a95e54
Author: Sławek Kapłoński <email address hidden>
Date: Wed Dec 27 11:49:44 2017 +0100

    [Fullstack] Shutdown tcpdump process gracefully

    In fullstack test for dscp marking packets tcpdump is used to capture
    packets send from one namespace (Fake VM) to another one.
    When tcpdump is closed quickly with SIGKILL signal it may not displays
    all packets and that might cause an issue with failed dscp marking test.

    Now tcpdump will be kill with SIGINT signal so it should display
    all captured packets to the stdout.
    Also it should now return to stderr summary of all captured/dropped
    packets which can be helpful in future debugging of issue with those
    tests if that will not solve the problem.

    Change-Id: Ib2d588d081a48f4f2b6e98a943bca95b9955a149
    Related-Bug: #1733649
    (cherry picked from commit b841a7f5d9a54468945e7eccecc91428797ebba9)

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/540458
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=93761220da156544ee3be821c4e9220600dd0745
Submitter: Zuul
Branch: stable/ocata

commit 93761220da156544ee3be821c4e9220600dd0745
Author: Sławek Kapłoński <email address hidden>
Date: Thu Jan 4 15:51:01 2018 +0100

    [Fullstack] Change how DSCP marking packets are tested

    In fullstack test test_dscp_marking_packets two fake hosts are
    created, each of them has got one fake instance (called sender and
    receiver).
    Instance called "sender" sends ICMP packets to instance called
    "receiver". In receiver's namespace tcpdump process is spawned with
    filter to match only packets marked with specified DSCP value.
    After sender instance successfully pings receiver, tcpdump process
    is killed and stdout from it was examined to search logged ICMP
    packets which were send from sender's IP to receiver's IP address.
    That check was failing sometimes as is described in bug report.

    It was failing when tcpdump doesn't capture any packets so there was
    nothing on stdout from it. But even in such case tcpdump reports on
    stderr summary of packets and it was like below:

    0 packets captured
    6 packets received by filter
    0 packets dropped by kernel

    which means that packets matching our filter was received by tcpdump but
    were probably not processed yet. See [1] for more details.

    So this patch changes filter used in tcpdump and way how its output is
    checked.
    Now in filter expression there are added src and dst IP addresses also so
    it will match only packets send from sender instance to receiver instance.
    After that tcpdump's stderr output is examined with regex to check if
    line like:

    X packets received by filter

    is there and if X value is different than 0. If so, it means that
    tcpdump received packets with wanted DSCP mark and test should pass.

    [1] https://unix.stackexchange.com/a/29369

    Change-Id: Ia3522237dc787edb90d162ac4a5535ff5d2a03d5
    Closes-Bug: #1733649
    (cherry picked from commit 386ec26b3d24f5862f6f76e0124a4370f45080cf)

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/neutron 10.0.5 release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/neutron 11.0.3 release.