Fix bug 2156 to select correct WIM connector class and prevent exceptions with missin...
[osm/RO.git] / NG-RO / osm_ng_ro / ns_thread.py
index 8bb8d4b..d2b00d6 100644 (file)
@@ -33,6 +33,7 @@ from shutil import rmtree
 import threading
 import time
 import traceback
+from typing import Dict
 from unittest.mock import Mock
 
 from importlib_metadata import entry_points
@@ -415,6 +416,7 @@ class VimInteractionVdu(VimInteractionBase):
 
             return "BUILD", ro_vim_item_update
         except (vimconn.VimConnException, NsWorkerException) as e:
+            self.logger.debug(traceback.format_exc())
             self.logger.error(
                 "task={} {} new-vm: {}".format(task_id, ro_task["target_id"], e)
             )
@@ -502,8 +504,10 @@ class VimInteractionVdu(VimInteractionBase):
                 vim_info_info = yaml.safe_load(vim_info["vim_info"])
                 if vim_info_info.get("name"):
                     vim_info["name"] = vim_info_info["name"]
-            except Exception:
-                pass
+            except Exception as vim_info_error:
+                self.logger.exception(
+                    f"{vim_info_error} occured while getting the vim_info from yaml"
+                )
         except vimconn.VimConnException as e:
             # Mark all tasks at VIM_ERROR status
             self.logger.error(
@@ -744,7 +748,7 @@ class VimInteractionFlavor(VimInteractionBase):
                     flavor_data = task["find_params"]["flavor_data"]
                     vim_flavor_id = target_vim.get_flavor_id_from_data(flavor_data)
                 except vimconn.VimConnNotFoundException:
-                    pass
+                    self.logger.warning("VimConnNotFoundException occured.")
 
             if not vim_flavor_id and task.get("params"):
                 # CREATE
@@ -1051,11 +1055,15 @@ class VimInteractionSdnNet(VimInteractionBase):
         try:
             # CREATE
             params = task["params"]
-            vlds_to_connect = params["vlds"]
-            associated_vim = params["target_vim"]
+            vlds_to_connect = params.get("vlds", [])
+            associated_vim = params.get("target_vim")
             # external additional ports
             additional_ports = params.get("sdn-ports") or ()
-            _, _, vim_account_id = associated_vim.partition(":")
+            _, _, vim_account_id = (
+                (None, None, None)
+                if associated_vim is None
+                else associated_vim.partition(":")
+            )
 
             if associated_vim:
                 # get associated VIM
@@ -1471,18 +1479,41 @@ class VimInteractionResize(VimInteractionBase):
             return "FAILED", ro_vim_item_update, db_task_update
 
 
-class NsWorker(threading.Thread):
-    REFRESH_BUILD = 5  # 5 seconds
-    REFRESH_ACTIVE = 60  # 1 minute
-    REFRESH_ERROR = 600
-    REFRESH_IMAGE = 3600 * 10
-    REFRESH_DELETE = 3600 * 10
-    QUEUE_SIZE = 100
-    terminate = False
+class ConfigValidate:
+    def __init__(self, config: Dict):
+        self.conf = config
+
+    @property
+    def active(self):
+        # default 1 min, allowed >= 60 or -1, -1 disables periodic checks
+        if (
+            self.conf["period"]["refresh_active"] >= 60
+            or self.conf["period"]["refresh_active"] == -1
+        ):
+            return self.conf["period"]["refresh_active"]
+
+        return 60
+
+    @property
+    def build(self):
+        return self.conf["period"]["refresh_build"]
 
+    @property
+    def image(self):
+        return self.conf["period"]["refresh_image"]
+
+    @property
+    def error(self):
+        return self.conf["period"]["refresh_error"]
+
+    @property
+    def queue_size(self):
+        return self.conf["period"]["queue_size"]
+
+
+class NsWorker(threading.Thread):
     def __init__(self, worker_index, config, plugins, db):
         """
-
         :param worker_index: thread index
         :param config: general configuration of RO, among others the process_id with the docker id where it runs
         :param plugins: global shared dict with the loaded plugins
@@ -1494,7 +1525,9 @@ class NsWorker(threading.Thread):
         self.plugin_name = "unknown"
         self.logger = logging.getLogger("ro.worker{}".format(worker_index))
         self.worker_index = worker_index
-        self.task_queue = queue.Queue(self.QUEUE_SIZE)
+        # refresh periods for created items
+        self.refresh_config = ConfigValidate(config)
+        self.task_queue = queue.Queue(self.refresh_config.queue_size)
         # targetvim: vimplugin class
         self.my_vims = {}
         # targetvim: vim information from database
@@ -1573,7 +1606,9 @@ class NsWorker(threading.Thread):
                 try:
                     mkdir(file_name)
                 except FileExistsError:
-                    pass
+                    self.logger.exception(
+                        "FileExistsError occured while processing vim_config."
+                    )
 
                 file_name = file_name + "/ca_cert"
 
@@ -1626,7 +1661,8 @@ class NsWorker(threading.Thread):
             self.logger.info("Unloaded {}".format(target_id))
             rmtree("{}:{}".format(target_id, self.worker_index))
         except FileNotFoundError:
-            pass  # this is raised by rmtree if folder does not exist
+            # This is raised by rmtree if folder does not exist.
+            self.logger.exception("FileNotFoundError occured while unloading VIM.")
         except Exception as e:
             self.logger.error("Cannot unload {}: {}".format(target_id, e))
 
@@ -1798,7 +1834,7 @@ class NsWorker(threading.Thread):
                     persistent_info={},
                 )
             else:  # sdn
-                plugin_name = "rosdn_" + vim["type"]
+                plugin_name = "rosdn_" + (vim.get("type") or vim.get("wim_type"))
                 step = "Loading plugin '{}'".format(plugin_name)
                 vim_module_conn = self._load_plugin(plugin_name, "sdn")
                 step = "Loading {}'".format(target_id)
@@ -1874,6 +1910,7 @@ class NsWorker(threading.Thread):
                         "tasks.status": ["SCHEDULED", "BUILD", "DONE", "FAILED"],
                         "locked_at.lt": now - self.task_locked_time,
                         "to_check_at.lt": self.time_last_task_processed,
+                        "to_check_at.gt": -1,
                     },
                     update_dict={"locked_by": self.my_id, "locked_at": now},
                     fail_on_empty=False,
@@ -2040,7 +2077,7 @@ class NsWorker(threading.Thread):
             "created_items", False
         )
 
-        self.logger.warning("Needed delete: {}".format(needed_delete))
+        self.logger.debug("Needed delete: {}".format(needed_delete))
         if my_task["status"] == "FAILED":
             return None, None  # TODO need to be retry??
 
@@ -2064,7 +2101,7 @@ class NsWorker(threading.Thread):
                     needed_delete = False
 
             if needed_delete:
-                self.logger.warning(
+                self.logger.debug(
                     "Deleting ro_task={} task_index={}".format(ro_task, task_index)
                 )
                 return self.item2class[my_task["item"]].delete(ro_task, task_index)
@@ -2169,13 +2206,59 @@ class NsWorker(threading.Thread):
                 fail_on_empty=False,
             )
 
-            self.logger.warning("ro_task_dependency={}".format(ro_task_dependency))
+            self.logger.debug("ro_task_dependency={}".format(ro_task_dependency))
             if ro_task_dependency:
                 for task_index, task in enumerate(ro_task_dependency["tasks"]):
                     if task["task_id"] == task_id:
                         return ro_task_dependency, task_index
         raise NsWorkerException("Cannot get depending task {}".format(task_id))
 
+    def update_vm_refresh(self):
+        """Enables the VM status updates if self.refresh_config.active parameter
+        is not -1 and than updates the DB accordingly
+
+        """
+        try:
+            self.logger.debug("Checking if VM status update config")
+            next_refresh = time.time()
+            if self.refresh_config.active == -1:
+                next_refresh = -1
+            else:
+                next_refresh += self.refresh_config.active
+
+            if next_refresh != -1:
+                db_ro_task_update = {}
+                now = time.time()
+                next_check_at = now + (24 * 60 * 60)
+                next_check_at = min(next_check_at, next_refresh)
+                db_ro_task_update["vim_info.refresh_at"] = next_refresh
+                db_ro_task_update["to_check_at"] = next_check_at
+
+                self.logger.debug(
+                    "Finding tasks which to be updated to enable VM status updates"
+                )
+                refresh_tasks = self.db.get_list(
+                    "ro_tasks",
+                    q_filter={
+                        "tasks.status": "DONE",
+                        "to_check_at.lt": 0,
+                    },
+                )
+                self.logger.debug("Updating tasks to change the to_check_at status")
+                for task in refresh_tasks:
+                    q_filter = {
+                        "_id": task["_id"],
+                    }
+                    self.db.set_one(
+                        "ro_tasks",
+                        q_filter=q_filter,
+                        update_dict=db_ro_task_update,
+                        fail_on_empty=True,
+                    )
+
+        except Exception as e:
+            self.logger.error(f"Error updating tasks to enable VM status updates: {e}")
+
     def _process_pending_tasks(self, ro_task):
         ro_task_id = ro_task["_id"]
         now = time.time()
@@ -2193,13 +2276,16 @@ class NsWorker(threading.Thread):
             next_refresh = time.time()
 
             if task["item"] in ("image", "flavor"):
-                next_refresh += self.REFRESH_IMAGE
+                next_refresh += self.refresh_config.image
             elif new_status == "BUILD":
-                next_refresh += self.REFRESH_BUILD
+                next_refresh += self.refresh_config.build
             elif new_status == "DONE":
-                next_refresh += self.REFRESH_ACTIVE
+                if self.refresh_config.active == -1:
+                    next_refresh = -1
+                else:
+                    next_refresh += self.refresh_config.active
             else:
-                next_refresh += self.REFRESH_ERROR
+                next_refresh += self.refresh_config.error
 
             next_check_at = min(next_check_at, next_refresh)
             db_ro_task_update["vim_info.refresh_at"] = next_refresh
@@ -2211,6 +2297,8 @@ class NsWorker(threading.Thread):
             if self.logger.getEffectiveLevel() == logging.DEBUG:
                 self._log_ro_task(ro_task, None, None, "TASK_WF", "GET_TASK")
             """
+            # Check if vim status refresh is enabled again
+            self.update_vm_refresh()
             # 0: get task_status_create
             lock_object = None
             task_status_create = None
@@ -2271,7 +2359,7 @@ class NsWorker(threading.Thread):
                                 dependency_task = dependency_ro_task["tasks"][
                                     dependency_task_index
                                 ]
-                                self.logger.warning(
+                                self.logger.debug(
                                     "dependency_ro_task={} dependency_task_index={}".format(
                                         dependency_ro_task, dependency_task_index
                                     )
@@ -2374,11 +2462,9 @@ class NsWorker(threading.Thread):
                                     # self._create_task(ro_task, task_index, task_depends, db_ro_task_update)
                                     _update_refresh(new_status)
                             else:
-                                if (
-                                    ro_task["vim_info"]["refresh_at"]
-                                    and now > ro_task["vim_info"]["refresh_at"]
-                                ):
-                                    new_status, db_vim_info_update = self.item2class[
+                                refresh_at = ro_task["vim_info"]["refresh_at"]
+                                if refresh_at and refresh_at != -1 and now > refresh_at:
+                                    (new_status, db_vim_info_update,) = self.item2class[
                                         task["item"]
                                     ].refresh(ro_task)
                                     _update_refresh(new_status)
@@ -2742,7 +2828,7 @@ class NsWorker(threading.Thread):
                 """
                 ro_task = self._get_db_task()
                 if ro_task:
-                    self.logger.warning("Task to process: {}".format(ro_task))
+                    self.logger.debug("Task to process: {}".format(ro_task))
                     time.sleep(1)
                     self._process_pending_tasks(ro_task)
                     busy = True