kytos-ng / kytos-end-to-end-tests

Kytos End-to-End Tests
0 stars 10 forks source link

RERUN tests/test_e2e_06_topology.py::TestE2ETopology::test_020_delete_switch #310

Closed viniarck closed 3 months ago

viniarck commented 3 months ago

Another recent rerun on this e2e test case below on 2024-06-09, it's worth reviewing and refactoring these test cases, these ones shouldn't be experiencing reruns relatively frequently, so let's assess if there's still interference on test setup/teardown and or if time sleeps are needed or need to be adapted cc'ing @Alopalao to keep this in your radar after the current priorities you have:

rerun: 0
tests/test_e2e_06_topology.py::TestE2ETopology::test_020_delete_switch: 2024-06-09,00:29:19.469163 - 2024-06-09,00:29:19.715384
self = <tests.test_e2e_06_topology.TestE2ETopology object at 0x7f3c41a9c1d0>

    def test_020_delete_switch(self):
        """Test api/kytos/topology/v3/switches/{switch_id} on DELETE
        Deleted:
            - Links: Ampath3 - Ampath2; Ampath3 - Ampath1
            - Switch: Ampath2
        """
        # Switch is not disabled, 409
        switch = "00:00:00:00:00:00:00:17"
        api_url = f'{KYTOS_API}/topology/v3/switches/{switch}'
        response = requests.delete(api_url)
        assert response.status_code == 409

        # Switch have links, 409
        api_url = f'{KYTOS_API}/topology/v3/switches/{switch}/disable'
        response = requests.post(api_url)
        assert response.status_code == 201

        api_url = f'{KYTOS_API}/topology/v3/switches/{switch}'
        response = requests.delete(api_url)
>       assert response.status_code == 409
E       assert 200 == 409
E        +  where 200 = <Response [200]>.status_code

tests/test_e2e_06_topology.py:123: AssertionError
=========================== rerun test summary info ============================
RERUN tests/test_e2e_06_topology.py::TestE2ETopology::test_020_delete_switch
= 239 passed, 8 skipped, 9 xfailed, 7 xpassed, 1295 warnings, 1 rerun in 12316.51s (3:25:16) =
italovalcy commented 3 months ago

Hello @viniarck and @Alopalao ,

I was looking into the logs for this execution and it seems that the test above was executed without giving enough time for Kytos to run the Link Discovery process. See below that Link UP are only generated after the second deletion request, resulting in 200/success (since at that point, the switch indexed didnt have any links).

# grep "2024-06-09 00:29:[12]" log | egrep 'Event handle_link_up Link|DELETE.*topology/v3/switches'
Jun  9 00:29:19 runner-rmtk68xb-project-171-concurrent-0 2024-06-09 00:29:19,481 (MainThread) uvicorn.access:INFO httptools_impl:489:  127.0.0.1:60942 - "DELETE /api/kytos/topology/v3/switches/00%3A00%3A00%3A00%3A00%3A00%3A00%3A17 HTTP/1.1" 409
Jun  9 00:29:19 runner-rmtk68xb-project-171-concurrent-0 2024-06-09 00:29:19,713 (MainThread) uvicorn.access:INFO httptools_impl:489:  127.0.0.1:60946 - "DELETE /api/kytos/topology/v3/switches/00%3A00%3A00%3A00%3A00%3A00%3A00%3A17 HTTP/1.1" 200
Jun  9 00:29:21 runner-rmtk68xb-project-171-concurrent-0 2024-06-09 00:29:21,035 (thread_pool_app_32) kytos.napps.kytos/mef_eline:INFO main:743:  Event handle_link_up Link(Interface('JAX1-eth14', 14, Switch('00:00:00:00:00:00:00:21')), Interface('Ampath4-eth14', 14, Switch('00:00:00:00:00:00:00:18')), dc67cf09e596bd4ea2c5d576f044404a85ed2f58cee8da2cbb39ba952e76ac67)
italovalcy commented 3 months ago

Hello @viniarck and @Alopalao ,

I was looking into the logs for this execution and it seems that the test above was executed without giving enough time for Kytos to run the Link Discovery process. See below that Link UP are only generated after the second deletion request, resulting in 200/success (since at that point, the switch indexed didnt have any links).

# grep "2024-06-09 00:29:[12]" log | egrep 'Event handle_link_up Link|DELETE.*topology/v3/switches'
Jun  9 00:29:19 runner-rmtk68xb-project-171-concurrent-0 2024-06-09 00:29:19,481 (MainThread) uvicorn.access:INFO httptools_impl:489:  127.0.0.1:60942 - "DELETE /api/kytos/topology/v3/switches/00%3A00%3A00%3A00%3A00%3A00%3A00%3A17 HTTP/1.1" 409
Jun  9 00:29:19 runner-rmtk68xb-project-171-concurrent-0 2024-06-09 00:29:19,713 (MainThread) uvicorn.access:INFO httptools_impl:489:  127.0.0.1:60946 - "DELETE /api/kytos/topology/v3/switches/00%3A00%3A00%3A00%3A00%3A00%3A00%3A17 HTTP/1.1" 200
Jun  9 00:29:21 runner-rmtk68xb-project-171-concurrent-0 2024-06-09 00:29:21,035 (thread_pool_app_32) kytos.napps.kytos/mef_eline:INFO main:743:  Event handle_link_up Link(Interface('JAX1-eth14', 14, Switch('00:00:00:00:00:00:00:21')), Interface('Ampath4-eth14', 14, Switch('00:00:00:00:00:00:00:18')), dc67cf09e596bd4ea2c5d576f044404a85ed2f58cee8da2cbb39ba952e76ac67)

The setup_method already includes a time sleep of 10seconds. However, this test file is using AmLight Topology, which has much more switches, interfaces and links than other topologies. Thus, I think only 10 seconds is too short to give enough time for Kytos to run LLDP.

Checking the logs I noticed that first PacketIns were received only almost 9 seconds after the switch connect, due to many reasons: Kytos overloaded with many Events to handle (specially interface created, topology updated, etc) and also OpenVSwitch running on the same host as Kytos will also suffer from Kytos high CPU usage.

viniarck commented 3 months ago

Good observation @italovalcy. Right. Let's try to do it. @Alopalao will take care of this eventually. Appreciated.