test_everflow_per_interface is flaky

[ysmanman]

Description

We observed that test_everflow_per_interface[ipv4] was flaky in T2 testing. The test scenario in question is to verify that packet ingressed from unselected ports ( those without acl rule being applioed) must not be mirrored. In the validation of received pkt, payload check is skipped:

https://github.com/sonic-net/sonic-mgmt/blob/1ee0fdc330907ffac9791e6a8a47263f23cc6e87/tests/everflow/everflow_test_utilities.py#L851-L852

As a result, some background packets like LLDP may be mistakenly matched, and thus results in false negative result.

Steps to reproduce the issue:

1. Stress test_everflow_per_interface in T2 testbed.

Describe the results you received:

Describe the results you expected:

Additional information you deem important:

**Output of `show version`:**

```
(paste your output here)
```

**Attach debug file `sudo generate_dump`:**

```
(paste your output here)
```

[ysmanman]

Add @arlakshm @wenyiz2021 for awareness.

[wenyiz2021]

thanks @ysmanman , sorry I don't quite understand why the testcase is flaky, is it because sometimes LLDP may be mistakenly matched and sometimes not?

[ysmanman]

thanks @ysmanman , sorry I don't quite understand why the testcase is flaky, is it because sometimes LLDP may be mistakenly matched and sometimes not?

Hi @wenyiz2021, in the test scenario, a test packet is injected from a port on which there is no acl rule configured, and test then checks there is no erspan pkt coming out from mirror dest port. However, if at the same time, a background packet like LLDP is received on any port that has acl rule configured, the mirrored LLDP packet will be received by the test and fail the test because the payload check of received packet is disabled.

[abdosi]

cc @judyjoseph

[ysmanman]

This is the backtrace and also pkt capture:

everflow/test_everflow_ipv6.py::TestIngressEverflowIPv6::test_fuzzy_subnets[cli] PASSED [ 32%] everflow/test_everflow_per_interface.py::test_everflow_per_interface[ipv4]
------------------------------------------------------------------------------------------------------------------- live log call ------------------------------------------------------------------------------------------------------------------- 19:04:25 init.pytest_runtest_call L0040 ERROR | Traceback (most recent call last):
File "/usr/local/lib/python2.7/dist-packages/_pytest/python.py", line 1464, in runtest
self.ihook.pytest_pyfunc_call(pyfuncitem=self)
File "/usr/local/lib/python2.7/dist-packages/pluggy/hooks.py", line 286, in call
return self._hookexec(self, self.get_hookimpls(), kwargs)
File "/usr/local/lib/python2.7/dist-packages/pluggy/manager.py", line 93, in _hookexec
return self._inner_hookexec(hook, methods, kwargs)
File "/usr/local/lib/python2.7/dist-packages/pluggy/manager.py", line 87, in
firstresult=hook.spec.opts.get("firstresult") if hook.spec else False,
File "/usr/local/lib/python2.7/dist-packages/pluggy/callers.py", line 208, in _multicall return outcome.get_result() File "/usr/local/lib/python2.7/dist-packages/pluggy/callers.py", line 81, in get_result _reraise(ex) # noqa File "/usr/local/lib/python2.7/dist-packages/pluggy/callers.py", line 187, in _multicall res = hook_impl.function(args) File "/usr/local/lib/python2.7/dist-packages/_pytest/python.py", line 174, in pytest_pyfunc_call testfunction(**testargs) File "/data/tests/everflow/test_everflow_per_interface.py", line 202, in test_everflow_per_interface send_and_verify_packet(ptfadapter, packet, exp_packet, ptf_idx, uplink_ports, False) File "/data/tests/everflow/test_everflow_per_interface.py", line 182, in send_and_verify_packet testutils.verify_no_packet_any(ptfadapter, pkt=expected_packet, ports=rx_ports) File "/usr/lib/python2.7/dist-packages/ptf/testutils.py", line 2476, in verify_no_packet_any verify_no_packet(test, pkt, (device, port)) File "/usr/lib/python2.7/dist-packages/ptf/testutils.py", line 2422, in verify_no_packet "port %r.\n%s" % (device, port, result.format())) File "/usr/lib/python2.7/unittest/case.py", line 410, in fail raise self.failureException(msg) AssertionError: Received packet that we expected not to receive on device 0, port 20. ========== RECEIVED ========== 0000 7A 1A 7E B4 82 EB 94 8E D3 5E 85 04 08 00 45 20 z.~......^....E 0010 00 88 00 00 00 00 03 2F B1 22 01 01 01 01 02 02 ......./."...... 0020 02 02 10 00 88 BE 00 00 00 00 10 00 00 00 00 0A ................ 0030 80 09 01 80 C2 00 00 0E CA CA 8C 1A FE 52 88 CC .............R.. 0040 02 07 04 96 07 FA F2 79 6A 04 0A 05 45 74 68 65 .......yj...Ethe 0050 72 6E 65 74 31 06 02 00 78 0A 0A 41 52 49 53 54 rnet1...x..ARIST 0060 41 30 31 54 31 0E 04 00 14 00 14 10 0C 05 01 0A A01T1........... 0070 FA 19 1A 02 00 0F 3E 58 00 FE 06 00 80 C2 01 00 ......>X........ 0080 00 FE 09 00 12 0F 03 03 00 0F 42 41 FE 06 00 12 ..........BA.... 0090 0F 04 24 14 00 00 ..$...

The captured the pkt was mirroed LLDP pkt. Test mistakenly thinks it's the test pkt because LLDP pkt has the same length as test pkt.

[abdosi]

@bingwang-ms please look into this. Looks like control packets coming in can result in failure of the test case.

[bingwang-ms]

Acked. Will check and get back later.

[bingwang-ms]

This is the backtrace and also pkt capture:

everflow/test_everflow_ipv6.py::TestIngressEverflowIPv6::test_fuzzy_subnets[cli] PASSED [ 32%] everflow/test_everflow_per_interface.py::test_everflow_per_interface[ipv4] ------------------------------------------------------------------------------------------------------------------- live log call ------------------------------------------------------------------------------------------------------------------- 19:04:25 init.pytest_runtest_call L0040 ERROR | Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/_pytest/python.py", line 1464, in runtest self.ihook.pytest_pyfunc_call(pyfuncitem=self) File "/usr/local/lib/python2.7/dist-packages/pluggy/hooks.py", line 286, in call return self._hookexec(self, self.get_hookimpls(), kwargs) File "/usr/local/lib/python2.7/dist-packages/pluggy/manager.py", line 93, in _hookexec return self._inner_hookexec(hook, methods, kwargs) File "/usr/local/lib/python2.7/dist-packages/pluggy/manager.py", line 87, in firstresult=hook.spec.opts.get("firstresult") if hook.spec else False, File "/usr/local/lib/python2.7/dist-packages/pluggy/callers.py", line 208, in _multicall return outcome.get_result() File "/usr/local/lib/python2.7/dist-packages/pluggy/callers.py", line 81, in get_result _reraise(ex) # noqa File "/usr/local/lib/python2.7/dist-packages/pluggy/callers.py", line 187, in _multicall res = hook_impl.function(args) File "/usr/local/lib/python2.7/dist-packages/_pytest/python.py", line 174, in pytest_pyfunc_call testfunction(**testargs) File "/data/tests/everflow/test_everflow_per_interface.py", line 202, in test_everflow_per_interface send_and_verify_packet(ptfadapter, packet, exp_packet, ptf_idx, uplink_ports, False) File "/data/tests/everflow/test_everflow_per_interface.py", line 182, in send_and_verify_packet testutils.verify_no_packet_any(ptfadapter, pkt=expected_packet, ports=rx_ports) File "/usr/lib/python2.7/dist-packages/ptf/testutils.py", line 2476, in verify_no_packet_any verify_no_packet(test, pkt, (device, port)) File "/usr/lib/python2.7/dist-packages/ptf/testutils.py", line 2422, in verify_no_packet "port %r.\n%s" % (device, port, result.format())) File "/usr/lib/python2.7/unittest/case.py", line 410, in fail raise self.failureException(msg) AssertionError: Received packet that we expected not to receive on device 0, port 20. ========== RECEIVED ========== 0000 7A 1A 7E B4 82 EB 94 8E D3 5E 85 04 08 00 45 20 z.~......^....E 0010 00 88 00 00 00 00 03 2F B1 22 01 01 01 01 02 02 ......./."...... 0020 02 02 10 00 88 BE 00 00 00 00 10 00 00 00 00 0A ................ 0030 80 09 01 80 C2 00 00 0E CA CA 8C 1A FE 52 88 CC .............R.. 0040 02 07 04 96 07 FA F2 79 6A 04 0A 05 45 74 68 65 .......yj...Ethe 0050 72 6E 65 74 31 06 02 00 78 0A 0A 41 52 49 53 54 rnet1...x..ARIST 0060 41 30 31 54 31 0E 04 00 14 00 14 10 0C 05 01 0A A01T1........... 0070 FA 19 1A 02 00 0F 3E 58 00 FE 06 00 80 C2 01 00 ......>X........ 0080 00 FE 09 00 12 0F 03 03 00 0F 42 41 FE 06 00 12 ..........BA.... 0090 0F 04 24 14 00 00 ..$...

The captured the pkt was mirroed LLDP pkt. Test mistakenly thinks it's the test pkt because LLDP pkt has the same length as test pkt.

I don't understand the issue. Even if the LLDP pkt has the same length as test packet, we still checked the src_ip, dest_ip, and many other fields. Can you please clarify why the LLDP packet can pass the check?

[ysmanman]

This is the backtrace and also pkt capture: everflow/test_everflow_ipv6.py::TestIngressEverflowIPv6::test_fuzzy_subnets[cli] PASSED [ 32%] everflow/test_everflow_per_interface.py::test_everflow_per_interface[ipv4] ------------------------------------------------------------------------------------------------------------------- live log call ------------------------------------------------------------------------------------------------------------------- 19:04:25 init.pytest_runtest_call L0040 ERROR | Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/_pytest/python.py", line 1464, in runtest self.ihook.pytest_pyfunc_call(pyfuncitem=self) File "/usr/local/lib/python2.7/dist-packages/pluggy/hooks.py", line 286, in call return self._hookexec(self, self.get_hookimpls(), kwargs) File "/usr/local/lib/python2.7/dist-packages/pluggy/manager.py", line 93, in _hookexec return self._inner_hookexec(hook, methods, kwargs) File "/usr/local/lib/python2.7/dist-packages/pluggy/manager.py", line 87, in firstresult=hook.spec.opts.get("firstresult") if hook.spec else False, File "/usr/local/lib/python2.7/dist-packages/pluggy/callers.py", line 208, in _multicall return outcome.get_result() File "/usr/local/lib/python2.7/dist-packages/pluggy/callers.py", line 81, in get_result _reraise(ex) # noqa File "/usr/local/lib/python2.7/dist-packages/pluggy/callers.py", line 187, in _multicall res = hook_impl.function(args) File "/usr/local/lib/python2.7/dist-packages/_pytest/python.py", line 174, in pytest_pyfunc_call testfunction(**testargs) File "/data/tests/everflow/test_everflow_per_interface.py", line 202, in test_everflow_per_interface send_and_verify_packet(ptfadapter, packet, exp_packet, ptf_idx, uplink_ports, False) File "/data/tests/everflow/test_everflow_per_interface.py", line 182, in send_and_verify_packet testutils.verify_no_packet_any(ptfadapter, pkt=expected_packet, ports=rx_ports) File "/usr/lib/python2.7/dist-packages/ptf/testutils.py", line 2476, in verify_no_packet_any verify_no_packet(test, pkt, (device, port)) File "/usr/lib/python2.7/dist-packages/ptf/testutils.py", line 2422, in verify_no_packet "port %r.\n%s" % (device, port, result.format())) File "/usr/lib/python2.7/unittest/case.py", line 410, in fail raise self.failureException(msg) AssertionError: Received packet that we expected not to receive on device 0, port 20. ========== RECEIVED ========== 0000 7A 1A 7E B4 82 EB 94 8E D3 5E 85 04 08 00 45 20 z.~......^....E 0010 00 88 00 00 00 00 03 2F B1 22 01 01 01 01 02 02 ......./."...... 0020 02 02 10 00 88 BE 00 00 00 00 10 00 00 00 00 0A ................ 0030 80 09 01 80 C2 00 00 0E CA CA 8C 1A FE 52 88 CC .............R.. 0040 02 07 04 96 07 FA F2 79 6A 04 0A 05 45 74 68 65 .......yj...Ethe 0050 72 6E 65 74 31 06 02 00 78 0A 0A 41 52 49 53 54 rnet1...x..ARIST 0060 41 30 31 54 31 0E 04 00 14 00 14 10 0C 05 01 0A A01T1........... 0070 FA 19 1A 02 00 0F 3E 58 00 FE 06 00 80 C2 01 00 ......>X........ 0080 00 FE 09 00 12 0F 03 03 00 0F 42 41 FE 06 00 12 ..........BA.... 0090 0F 04 24 14 00 00 ..$... The captured the pkt was mirroed LLDP pkt. Test mistakenly thinks it's the test pkt because LLDP pkt has the same length as test pkt.

I don't understand the issue. Even if the LLDP pkt has the same length as test packet, we still checked the src_ip, dest_ip, and many other fields. Can you please clarify why the LLDP packet can pass the check?

Because test only verifies erspan header and doesn't check original pkt at all https://github.com/sonic-net/sonic-mgmt/blob/8f22f6db7c3df5da8c60b82d760061f1deaf4e15/tests/everflow/everflow_test_utilities.py#L880