search

kytos-ng / of_core

Kytos Main OpenFlow Network Application (NApp)
MIT License
0 stars 5 forks source link

strange behavior with recent changes - non-stop log messages for Overlapping stats request #76

Closed italovalcy closed 1 year ago

italovalcy commented 2 years ago

Hi,

Just come across this strange behavior when running the most recent version of Kytos-ng container (amlight/kytos:latest) with Mininet (using Amlight topo): non-stop log messages for Overlapping stats request.

Steps that I followed:

  1. Run Kytos in a container with amlight/kytos:latest and services from kytos-ng/kytos compose file.
  2. Start Kytos and Mininet (using AmLight topo) 
    tmux new-session -d -s kytosserver kytosd -f --database mongodb
tmux new-session -d -s mn mn --custom tests/helpers.py --topo=amlight --controller=remote,ip=127.0.0.1
  3. Create a few EVCs (I've created 100 EVCs using dynamic path between the two switches with longer diameter): 
    
# cat /mydata/bulk-create-evc-dyn.sh
#!/bin/bash

IFACEID_A=00:00:00:00:00:00:00:16:55 IFACEID_Z=00:00:00:00:00:00:00:21:60

VLAN_A=$1 VLAN_Z=$2 test -z "$VLAN_Z" && VLAN_Z=$VLAN_A

for VLAN in $(seq $VLAN_A $VLAN_Z); do curl --max-time 120 -H 'Content-type: application/json' -X POST http://127.0.0.1:8181/api/kytos/mef_eline/v2/evc -d '{"name": "my evc '$VLAN'", "dynamic_backup_path": true, "enabled": true, "uni_a": {"tag": {"value": '$VLAN', "tag_type": 1}, "interface_id": "'$IFACEID_A'"}, "uni_z": {"tag": {"value": '$VLAN', "tag_type": 1}, "interface_id": "'$IFACEID_Z'"}}' done

/mydata/bulk-create-evc-dyn.sh 401 500

4. Observe the log messages:

2022-08-04 12:44:12,896 - INFO [kytos.napps.kytos/of_core] [main.py:79:_check_overlapping_multipart_request] (Thread-4185) Overlapping stats request: switch 00:00:00:00:00:00:00:11 flows_xid 2245245623 ports_xid 2230757636 2022-08-04 12:44:13,732 - INFO [kytos.napps.kytos/of_core] [main.py:79:_check_overlapping_multipart_request] (Thread-4181) Overlapping stats request: switch 00:00:00:00:00:00:00:19 flows_xid 2632122293 ports_xid 4061814385 2022-08-04 12:44:13,895 - INFO [kytos.napps.kytos/of_core] [main.py:79:_check_overlapping_multipart_request] (Thread-4182) Overlapping stats request: switch 00:00:00:00:00:00:00:14 flows_xid 719258694 ports_xid 1499754075 2022-08-04 12:44:14,069 - INFO [kytos.napps.kytos/of_core] [main.py:79:_check_overlapping_multipart_request] (Thread-4183) Overlapping stats request: switch 00:00:00:00:00:00:00:16 flows_xid 2025405599 ports_xid 2101082769 2022-08-04 12:44:14,231 - INFO [kytos.napps.kytos/of_core] [main.py:79:_check_overlapping_multipart_request] (Thread-4184) Overlapping stats request: switch 00:00:00:00:00:00:00:12 flows_xid 4098394341 ports_xid 3220156085 2022-08-04 12:44:16,249 - INFO [kytos.napps.kytos/of_core] [main.py:79:_check_overlapping_multipart_request] (Thread-4188) Overlapping stats request: switch 00:00:00:00:00:00:00:20 flows_xid 1660225087 ports_xid 3635157287 2022-08-04 12:44:16,409 - INFO [kytos.napps.kytos/of_core] [main.py:79:_check_overlapping_multipart_request] (Thread-4189) Overlapping stats request: switch 00:00:00:00:00:00:00:15 flows_xid 1292088629 ports_xid 1538582635 2022-08-04 12:44:16,560 - INFO [kytos.napps.kytos/of_core] [main.py:79:_check_overlapping_multipart_request] (Thread-4190) Overlapping stats request: switch 00:00:00:00:00:00:00:21 flows_xid 417559522 ports_xid 2267888300 2022-08-04 12:44:16,727 - INFO [kytos.napps.kytos/of_core] [main.py:79:_check_overlapping_multipart_request] (Thread-4191) Overlapping stats request: switch 00:00:00:00:00:00:00:17 flows_xid 1468680350 ports_xid 3821115459 2022-08-04 12:44:17,043 - INFO [kytos.napps.kytos/of_core] [main.py:79:_check_overlapping_multipart_request] (Thread-4193) Overlapping stats request: switch 00:00:00:00:00:00:00:14 flows_xid 719258694 ports_xid 1499754075 2022-08-04 12:44:17,209 - INFO [kytos.napps.kytos/of_core] [main.py:79:_check_overlapping_multipart_request] (Thread-4194) Overlapping stats request: switch 00:00:00:00:00:00:00:16 flows_xid 2025405599 ports_xid 2101082769 2022-08-04 12:44:17,380 - INFO [kytos.napps.kytos/of_core] [main.py:79:_check_overlapping_multipart_request] (Thread-4195) Overlapping stats request: switch 00:00:00:00:00:00:00:12 flows_xid 4098394341 ports_xid 3220156085 2022-08-04 12:44:19,073 - INFO [kytos.napps.kytos/of_core] [main.py:79:_check_overlapping_multipart_request] (Thread-4197) Overlapping stats request: switch 00:00:00:00:00:00:00:13 flows_xid 4150846299 ports_xid 1613629752 2022-08-04 12:44:19,226 - INFO [kytos.napps.kytos/of_core] [main.py:79:_check_overlapping_multipart_request] (Thread-4198) Overlapping stats request: switch 00:00:00:00:00:00:00:18 flows_xid 2167957364 ports_xid 1822900004



It is worth mentioning that I do have local changes on Kytos/mef_eline Napp, but those changes have no immediate relation with the flow_stats retrieval routine shown above. I can certainly test again with a clean env later on.

No errors on logs or Kytos console were reported.
viniarck commented 2 years ago

I've analyzed this with @italovalcy it turns out that STATS_INTERVAL = 3 being used was too low for scenario that has a topology with 10+ switches. This low value was used since Italo was also anticipating e2e tests executions. Thanks for reporting this, Italo, better sooner than later. If any unexpected new behavior is observed let me know.

viniarck commented 1 year ago

I've analyzed this with @italovalcy it turns out that STATS_INTERVAL = 3 being used was too low for scenario that has a topology with 10+ switches. This low value was used since Italo was also anticipating e2e tests executions. Thanks for reporting this, Italo, better sooner than later. If any unexpected new behavior is observed let me know.

I'll go ahead and close this issue.