Core/starter #501

Alopalao · 2024-09-16T16:23:19Z

Closes #500

Summary

Kytos now waits for uvicorn to start before loading NApps.

Local Tests

Started kytos

End-to-End Tests

Progress so far:

+ python3 -m pytest tests/ --reruns 2 -r fEr
============================= test session starts ==============================
platform linux -- Python 3.11.2, pytest-8.1.1, pluggy-1.5.0
rootdir: /tests
plugins: rerunfailures-13.0, timeout-2.2.0, anyio-4.3.0
collected 267 items

tests/test_e2e_01_kytos_startup.py ..                                    [  0%]
tests/test_e2e_05_topology.py ..................                         [  7%]
tests/test_e2e_06_topology.py ....                                       [  8%]
tests/test_e2e_10_mef_eline.py ..........ss.....x.....x................  [ 23%]
tests/test_e2e_11_mef_eline.py ......                                    [ 26%]
tests/test_e2e_12_mef_eline.py .....Xx.                                  [ 29%]
tests/test_e2e_13_mef_eline.py ....Xs.s.....Xs.s.XXxX.xxxx..X........... [ 44%]
.                                                                        [ 44%]
tests/test_e2e_14_mef_eline.py x                                         [ 45%]
tests/test_e2e_15_mef_eline.py .....                                     [ 47%]
tests/test_e2e_16_mef_eline.py ..                                        [ 47%]
tests/test_e2e_20_flow_manager.py ......................                 [ 56%]
tests/test_e2e_21_flow_manager.py ...                                    [ 57%]
tests/test_e2e_22_flow_manager.py ...............                        [ 62%]
tests/test_e2e_23_flow_manager.py ..............                         [ 68%]
tests/test_e2e_30_of_lldp.py .R...                                       [ 69%]
tests/test_e2e_31_of_lldp.py ...                                         [ 70%]
tests/test_e2e_32_of_lldp.py ...                                         [ 71%]
tests/test_e2e_40_sdntrace.py ................                           [ 77%]
tests/test_e2e_41_kytos_auth.py ........                                 [ 80%]
tests/test_e2e_42_sdntrace.py ..                                         [ 81%]
tests/test_e2e_50_maintenance.py ............................            [ 92%]
tests/test_e2e_60_of_multi_table.py .....                                [ 94%]
tests/test_e2e_70_kytos_stats.py ........                                [ 97%]
tests/test_e2e_80_pathfinder.py ss......                                 [100%]

Consolo logging

The console logging has changed. Now the following lines will show at the beginning of kytos start:

INFO:     Started server process [290729]
2024-09-16 14:56:26,612 - INFO [uvicorn.error] (MainThread) Waiting for application startup.
t2024-09-16 14:56:26,627 - INFO [uvicorn.error] (MainThread) Application startup complete.
INFO:     Uvicorn running on http://0.0.0.0:8181 (Press CTRL+C to quit)

Alopalao · 2024-09-16T16:23:54Z

If this PR is approved, would this update need a new version?

viniarck

Excellent solution @Alopalao. Yes, it needs to bump the version, we'll ship it as a patch. I'm also not seeing the warning of of_lldp and warning retries due to the endpoint not being ready, nice. Great to have the initialization correct with this wait now to minimize other type of issues.

One remaning thing though, we're still starting auth core endpoints, so in theory those endpoins would still not be ready to be used too, right? I have an impression that we need to also only initialize them after the api server got started, can you review this part too?

2024-09-16 16:22:36,110 - INFO [kytos.core.db] (MainThread) Starting DB connection
2024-09-16 16:22:36,110 - INFO [kytos.core.db] (MainThread) Trying to run 'hello' command on MongoDB...
2024-09-16 16:22:36,118 - INFO [kytos.core.db] (MainThread) Ran 'hello' command on MongoDB successfully. It's ready!
2024-09-16 16:22:36,128 - INFO [kytos.core.api_server] (MainThread) Started /api/kytos/core/auth/login/ - GET
2024-09-16 16:22:36,128 - INFO [kytos.core.api_server] (MainThread) Started /api/kytos/core/auth/users/ - GET
2024-09-16 16:22:36,128 - INFO [kytos.core.api_server] (MainThread) Started /api/kytos/core/auth/users/{username} - GET
2024-09-16 16:22:36,128 - INFO [kytos.core.api_server] (MainThread) Started /api/kytos/core/auth/users/ - POST
2024-09-16 16:22:36,128 - INFO [kytos.core.api_server] (MainThread) Started /api/kytos/core/auth/users/{username} - DELETE
2024-09-16 16:22:36,128 - INFO [kytos.core.api_server] (MainThread) Started /api/kytos/core/auth/users/{username} - PATCH
2024-09-16 16:22:36,128 - INFO [kytos.core.controller] (MainThread) /home/viniarck/repos/kytos/.direnv/python-3.11/var/run/kytos
2024-09-16 16:22:36,129 - INFO [kytos.core.controller] (MainThread) Starting Kytos - Kytos Controller
2024-09-16 16:22:36,138 - INFO [kytos.core.controller] (MainThread) Starting TCP server: <kytos.core.atcp_server.KytosServer object at 0x7fbd6408a9d0>
2024-09-16 16:22:36,138 - INFO [kytos.core.atcp_server] (MainThread) Kytos listening at 0.0.0.0:6653
INFO:     Started server process [46483]
2024-09-16 16:22:36,149 - INFO [uvicorn.error] (MainThread) Waiting for application startup.
2024-09-16 16:22:36,152 - INFO [uvicorn.error] (MainThread) Application startup complete.

kytos/core/controller.py

viniarck

@Alopalao, it's pretty much ready to land, except for another minor adjacent startup thing that I noticed:

We should start the TCP server right after the API server is started. Otherwise, in a case where there's a hiccup and for some reason if there's a dealyed CPU processing connections would start to get dropped since switches could connect but of_core and NApps initialization would be ready but TCP server would be (very rare for this to happen but since you're at it, let's get that corrected too):

2024-09-17 10:18:41,626 - INFO [kytos.core.db] (MainThread) Starting DB connection
2024-09-17 10:18:41,627 - INFO [kytos.core.db] (MainThread) Trying to run 'hello' command on MongoDB...
2024-09-17 10:18:41,635 - INFO [kytos.core.db] (MainThread) Ran 'hello' command on MongoDB successfully. It's ready!
2024-09-17 10:18:41,635 - INFO [kytos.core.controller] (MainThread) /home/viniarck/repos/kytos/.direnv/python-3.11/var/run/kytos
2024-09-17 10:18:41,635 - INFO [kytos.core.controller] (MainThread) Starting Kytos - Kytos Controller
2024-09-17 10:18:41,640 - INFO [kytos.core.controller] (MainThread) Starting TCP server: <kytos.core.atcp_server.KytosServer object at 0x7f88de025950>
2024-09-17 10:18:41,640 - INFO [kytos.core.atcp_server] (MainThread) Kytos listening at 0.0.0.0:6653
INFO:     Started server process [17743]
2024-09-17 10:18:41,649 - INFO [uvicorn.error] (MainThread) Waiting for application startup.
2024-09-17 10:18:41,651 - INFO [uvicorn.error] (MainThread) Application startup complete.
INFO:     Uvicorn running on http://0.0.0.0:8181 (Press CTRL+C to quit)
2024-09-17 10:18:42,081 - INFO [kytos.core.atcp_server] (MainThread) New connection from 127.0.0.1:37596
2024-09-17 10:18:42,081 - INFO [kytos.core.atcp_server] (MainThread) New connection from 127.0.0.1:37602
2024-09-17 10:18:42,082 - INFO [kytos.core.atcp_server] (MainThread) New connection from 127.0.0.1:37604
2024-09-17 10:18:43,083 - INFO [kytos.core.atcp_server] (MainThread) Connection lost with client 127.0.0.1:37596. Reason: Request closed by client
2024-09-17 10:18:43,084 - INFO [kytos.core.atcp_server] (MainThread) Connection lost with client 127.0.0.1:37602. Reason: Request closed by client
2024-09-17 10:18:43,086 - INFO [kytos.core.atcp_server] (MainThread) Connection lost with client 127.0.0.1:37604. Reason: Request closed by client
2024-09-17 10:18:44,084 - INFO [kytos.core.atcp_server] (MainThread) New connection from 127.0.0.1:59938
2024-09-17 10:18:44,085 - INFO [kytos.core.atcp_server] (MainThread) New connection from 127.0.0.1:59946
2024-09-17 10:18:44,085 - INFO [kytos.core.atcp_server] (MainThread) New connection from 127.0.0.1:59958
2024-09-17 10:18:45,085 - INFO [kytos.core.atcp_server] (MainThread) Connection lost with client 127.0.0.1:59938. Reason: Request closed by client
2024-09-17 10:18:45,086 - INFO [kytos.core.atcp_server] (MainThread) Connection lost with client 127.0.0.1:59946. Reason: Request closed by client
2024-09-17 10:18:45,086 - INFO [kytos.core.atcp_server] (MainThread) Connection lost with client 127.0.0.1:59958. Reason: Request closed by client
2024-09-17 10:18:46,091 - INFO [kytos.core.atcp_server] (MainThread) New connection from 127.0.0.1:59962
2024-09-17 10:18:46,091 - INFO [kytos.core.atcp_server] (MainThread) New connection from 127.0.0.1:59974
2024-09-17 10:18:46,092 - INFO [kytos.core.atcp_server] (MainThread) New connection from 127.0.0.1:59984

To simulate it you can temporarily set a higher sleep interval for the api server wait method:

diff --git a/kytos/core/controller.py b/kytos/core/controller.py
index 787092b8..6a5f5065 100644
--- a/kytos/core/controller.py
+++ b/kytos/core/controller.py
@@ -363,7 +363,7 @@ class Controller:
     async def _wait_api_server_started(self):
         """Use this method to wait for Uvicorn server to start."""
         while not self.api_server.server.started:
-            await asyncio.sleep(0.1)
+            await asyncio.sleep(5)

Alopalao · 2024-09-17T14:13:58Z

Changed the order of servers. Although now TCP server is not awaited and will only start at the end controller.start_controller()

viniarck

Excellent fix and adjacent enhancements, Aldo. Let's ship it.

Alopalao added 2 commits September 12, 2024 09:53

Changed controller started to async

c57543d

Added tests

1a1df5b

Alopalao requested a review from a team as a code owner September 16, 2024 16:23

viniarck reviewed Sep 16, 2024

View reviewed changes

kytos/core/controller.py Outdated Show resolved Hide resolved

Updated changelog

a2bffec

viniarck self-requested a review September 17, 2024 13:02

viniarck reviewed Sep 17, 2024

View reviewed changes

Updated order of servers starts

ccb9149

viniarck self-requested a review September 17, 2024 16:23

viniarck approved these changes Sep 17, 2024

View reviewed changes

viniarck merged commit 9e5d25f into master Sep 17, 2024
2 checks passed

viniarck deleted the core/starter branch September 17, 2024 16:27

viniarck mentioned this pull request Sep 17, 2024

Kytos running in foreground takes forever to stop #492

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Core/starter #501

Core/starter #501

Alopalao commented Sep 16, 2024 •

edited

Loading

Alopalao commented Sep 16, 2024

viniarck left a comment •

edited

Loading

viniarck left a comment

Alopalao commented Sep 17, 2024

viniarck left a comment

Core/starter #501

Core/starter #501

Conversation

Alopalao commented Sep 16, 2024 • edited Loading

Summary

Local Tests

End-to-End Tests

Consolo logging

Alopalao commented Sep 16, 2024

viniarck left a comment • edited Loading

Choose a reason for hiding this comment

viniarck left a comment

Choose a reason for hiding this comment

Alopalao commented Sep 17, 2024

viniarck left a comment

Choose a reason for hiding this comment

Alopalao commented Sep 16, 2024 •

edited

Loading

viniarck left a comment •

edited

Loading