RuntimeError: dictionary changed size during iteration on shared self.circuits dict

[viniarck]

It turns out that self.circuits is also vulnerable to RuntimeError: dictionary changed size, see this #175 (comment) for more info. There are more points in the code where this can happen, I'll point them out later for completeness.

To facilitate to reproduce the issue:

• You can introduce some time.sleep on parts of the code where self.circuits is being iterated on without any locks or shallow copy, and then you have to force an insertion by creating a new circuit just so the iterated collection would change its size, for instance if you add this time.sleep:

diff --git a/main.py b/main.py
index 46b1374..ea0ebc8 100644
--- a/main.py
+++ b/main.py
@@ -3,6 +3,7 @@

 NApp to provision circuits from user request.
 """
+import time
 from threading import Lock

 from flask import jsonify, request
@@ -650,6 +651,8 @@ class Main(KytosNApp):
         """Change circuit when link is down or under_mantenance."""
         log.debug("Event handle_link_down %s", event)
         for evc in self.circuits.values():
+            log.info("handle_link_down before sleep...")
+            time.sleep(20)
             with evc.lock:
                 if evc.is_affected_by_link(event.content["link"]):
                     log.debug(f"Handling evc {evc.id} on link down")
(END)

• When you see the "handle_link_down before sleep..." after you simulate a link down, if you try to create a new circuit you should get the traceback:

2)>, KytosEvent('kytos/topology.link_down', {'link': Link(Interface('s1-eth2', 2, Switch('00:00:00:00:00:00:00:01')), Interface('s2-eth2', 2, Switch('00:00:00:00:00:00:00:02'))), 'reason': 'link down'}, 0)) traceback: Traceback (most recent call last):,   File "/home/viniarck/repos/kytos/kytos/core/helpers.py", line 146, in handler_context_apm,     result = handler(*args),   File "/home/viniarck/repos/napps/napps/kytos/mef_eline/main.py", line 648, in on_link_down,     self.handle_link_down(event),   File "/home/viniarck/repos/napps/napps/kytos/mef_eline/main.py", line 653, in handle_link_down,     for evc in self.circuits.values():, RuntimeError: dictionary changed size during iteration,k

2022-08-11 20:07:09,749 - INFO [kytos.napps.kytos/mef_eline] (thread_pool_app_3) handle_link_down before sleep...
2022-08-11 20:07:13,324 - INFO [kytos.napps.kytos/flow_manager] (Thread-110) Send FlowMod from request dpid: 00:00:00:00:00:00:00:01, command: delete, force: True, flows_dict: {'flows':[{'cookie': 12312914265833437510, 'cookie_mask': 18446744073709551615}], 'force': True}
2022-08-11 20:07:13,334 - INFO [kytos.napps.kytos/flow_manager] (Thread-111) Send FlowMod from request dpid: 00:00:00:00:00:00:00:03, command: delete, force: True, flows_dict: {'flows':[{'cookie': 12312914265833437510, 'cookie_mask': 18446744073709551615}], 'force': True}
2022-08-11 20:07:13,350 - WARNING [kytos.napps.kytos/mef_eline] (Thread-109) EVC(e04249c4d77946, evc1) was not deployed. No available path was found.
2022-08-11 20:07:26,612 - INFO [kytos.napps.kytos/mef_eline] (mef_eline) EVC(e04249c4d77946, evc1) enabled but inactive - activating
2022-08-11 20:07:27,643 - INFO [kytos.napps.kytos/flow_manager] (Thread-119) Send FlowMod from request dpid: 00:00:00:00:00:00:00:01, command: delete, force: True, flows_dict: {'flows':[{'cookie': 12315191667550513988, 'cookie_mask': 18446744073709551615}], 'force': True}
2022-08-11 20:07:27,653 - INFO [kytos.napps.kytos/flow_manager] (Thread-120) Send FlowMod from request dpid: 00:00:00:00:00:00:00:03, command: delete, force: True, flows_dict: {'flows':[{'cookie': 12315191667550513988, 'cookie_mask': 18446744073709551615}], 'force': True}
2022-08-11 20:07:27,665 - WARNING [kytos.napps.kytos/mef_eline] (Thread-118) EVC(e85992ad32eb44, evc1) was not deployed. No available path was found.
2022-08-11 20:07:29,761 - INFO [kytos.napps.kytos/flow_manager] (Thread-122) Send FlowMod from request dpid: 00:00:00:00:00:00:00:02, command: delete, force: True, flows_dict: {'flows':[{'cookie': 12270638456027046726, 'cookie_mask': 18446744073709551615}], 'force': True}
2022-08-11 20:07:29,785 - INFO [kytos.napps.kytos/flow_manager] (Thread-123) Send FlowMod from request dpid: 00:00:00:00:00:00:00:01, command: delete, force: True, flows_dict: {'flows':[{'cookie': 12270638456027046726, 'cookie_mask': 18446744073709551615}], 'force': True}
2022-08-11 20:07:29,811 - INFO [kytos.napps.kytos/flow_manager] (Thread-124) Send FlowMod from request dpid: 00:00:00:00:00:00:00:03, command: delete, force: True, flows_dict: {'flows':[{'cookie': 12270638456027046726, 'cookie_mask': 18446744073709551615}], 'force': True}
2022-08-11 20:07:29,915 - WARNING [kytos.napps.kytos/mef_eline] (thread_pool_app_3) EVC(4a10a9c2bd6346, evc1) was not deployed. No available path was found.
2022-08-11 20:07:29,919 - ERROR [kytos.core.helpers] (thread_pool_app_3) listen_to handler: <function Main.on_link_down at 0x7f130c237a60>, args: (<Main(mef_eline, started 13971553778643
2)>, KytosEvent('kytos/topology.link_down', {'link': Link(Interface('s1-eth2', 2, Switch('00:00:00:00:00:00:00:01')), Interface('s2-eth2', 2, Switch('00:00:00:00:00:00:00:02'))), 'reason': 'link down'}, 0)) traceback: Traceback (most recent call last):,   File "/home/viniarck/repos/kytos/kytos/core/helpers.py", line 146, in handler_context_apm,     result = handler(*args),   File "/home/viniarck/repos/napps/napps/kytos/mef_eline/main.py", line 648, in on_link_down,     self.handle_link_down(event),   File "/home/viniarck/repos/napps/napps/kytos/mef_eline/main.py", line 653, in handle_link_down,     for evc in self.circuits.values():, RuntimeError: dictionary changed size during iteration,k

[italovalcy]

@viniarck I'm very glad you found this! I've pushed commit fe44385 to fix the issues on PR #175 as a workaround for this. In the future, we can also leverage MongoDB direct queries and maybe even remove the self.circuits local copy. Looking into mef_eline remain code, I couldn't find other places where this vulnerability is present (except circuit_scheduler, which is also referred as part of the evc.as_dict() call):

> egrep "for .*self\..*" * -R
main.py:        for circuit in tuple(self.circuits.values()):
main.py:        for circuit in tuple(self.circuits.values()):
main.py:        for evc in self.circuits.copy().values():
main.py:        for evc in self.circuits.copy().values():
models/evc.py:        for attribute in self.required_attributes:
models/evc.py:            sc.as_dict() for sc in self.circuit_scheduler
models/evc.py:        for dpid, flows in self._prepare_nni_flows(path).items():
models/evc.py:        for dpid, flows in self._prepare_uni_flows(path, skip_in=True).items():
models/evc.py:            for use_path in self.discover_new_paths():
models/evc.py:        for use_path in self.get_failover_path_candidates():
models/evc.py:        for incoming, outcoming in self.links_zipped(path):
models/evc.py:        for dpid, flows in self._prepare_nni_flows(path).items():
models/evc.py:        for link, trace1, trace2 in zip(self.current_path,

Please let me know if you wanna leave the issue open for handling this remaining code or even refactor to leverage MongoDB.

[viniarck]

: for dpid, flows in self._prepare_nni_flows(path).items():
models/evc.py: for dpid, flows in self._prepare_uni_flows(path, skip_in=True).items():
models/evc.py: for use_path in self.discover_new_paths():
models/evc.py: for use_path in self.get_failover_path_candidates():
models/evc.py: for incoming, outcoming in self.links_zipped(path):
models/evc.py: for dpid, flows in self._prepare_nni_flows(path).items():
models/evc.py: for link, trace1, trace2 in zip(self.current_path,

@italovalcy, sounds good, I agree, shallow copy should be good for now, and then in a next opportunity try to offload more things to MongoDB. It's up to you if you'd rather use this issue for this future opportunity on MongoDB or map a new one. I also didn't find any other points than the ones you've posted here, on models/evc.py several points is passign the same ref but it's not getting inserted again from what I followed, so, it seems safe. Thanks for patching this.