A ro_task can contain several 'tasks', each one with a target, where to store the results
"""
-import logging
-import queue
-import threading
-import time
-import yaml
from copy import deepcopy
from http import HTTPStatus
+import logging
from os import mkdir
-from pkg_resources import iter_entry_points
+import queue
from shutil import rmtree
+import threading
+import time
+import traceback
from unittest.mock import Mock
-# from osm_common import dbmongo, dbmemory, fslocal, fsmongo, msglocal, msgkafka, version as common_version
+from importlib_metadata import entry_points
from osm_common.dbbase import DbException
-from osm_ro_plugin.vim_dummy import VimDummyConnector
-from osm_ro_plugin.sdn_dummy import SdnDummyConnector
-from osm_ro_plugin import vimconn, sdnconn
from osm_ng_ro.vim_admin import LockRenew
-
+from osm_ro_plugin import sdnconn, vimconn
+from osm_ro_plugin.sdn_dummy import SdnDummyConnector
+from osm_ro_plugin.vim_dummy import VimDummyConnector
+import yaml
__author__ = "Alfonso Tierno"
__date__ = "$28-Sep-2017 12:07:15$"
created = False
created_items = {}
target_vim = self.my_vims[ro_task["target_id"]]
+ mgmtnet = False
+ mgmtnet_defined_in_vim = False
try:
# FIND
# if management, get configuration of VIM
if task["find_params"].get("filter_dict"):
vim_filter = task["find_params"]["filter_dict"]
- # mamagement network
+ # management network
elif task["find_params"].get("mgmt"):
+ mgmtnet = True
if deep_get(
self.db_vims[ro_task["target_id"]],
"config",
"management_network_id",
):
+ mgmtnet_defined_in_vim = True
vim_filter = {
"id": self.db_vims[ro_task["target_id"]]["config"][
"management_network_id"
"config",
"management_network_name",
):
+ mgmtnet_defined_in_vim = True
vim_filter = {
"name": self.db_vims[ro_task["target_id"]]["config"][
"management_network_name"
vim_nets = target_vim.get_network_list(vim_filter)
if not vim_nets and not task.get("params"):
- raise NsWorkerExceptionNotFound(
- "Network not found with this criteria: '{}'".format(
- task.get("find_params")
+ # If there is mgmt-network in the descriptor,
+ # there is no mapping of that network to a VIM network in the descriptor,
+ # also there is no mapping in the "--config" parameter or at VIM creation;
+ # that mgmt-network will be created.
+ if mgmtnet and not mgmtnet_defined_in_vim:
+ net_name = (
+ vim_filter.get("name")
+ if vim_filter.get("name")
+ else vim_filter.get("id")[:16]
+ )
+ vim_net_id, created_items = target_vim.new_network(
+ net_name, None
+ )
+ self.logger.debug(
+ "Created mgmt network vim_net_id: {}".format(vim_net_id)
+ )
+ created = True
+ else:
+ raise NsWorkerExceptionNotFound(
+ "Network not found with this criteria: '{}'".format(
+ task.get("find_params")
+ )
)
- )
elif len(vim_nets) > 1:
raise NsWorkerException(
"More than one network found with this criteria: '{}'".format(
"created": created,
"created_items": created_items,
"vim_details": None,
+ "vim_message": None,
}
self.logger.debug(
"task={} {} new-net={} created={}".format(
ro_vim_item_update = {
"vim_status": "VIM_ERROR",
"created": created,
- "vim_details": str(e),
+ "vim_message": str(e),
}
return "FAILED", ro_vim_item_update
ro_vim_item_update["vim_name"] = vim_info.get("name")
if vim_info["status"] in ("ERROR", "VIM_ERROR"):
- if ro_task["vim_info"]["vim_details"] != vim_info.get("error_msg"):
- ro_vim_item_update["vim_details"] = vim_info.get("error_msg")
+ if ro_task["vim_info"]["vim_message"] != vim_info.get("error_msg"):
+ ro_vim_item_update["vim_message"] = vim_info.get("error_msg")
elif vim_info["status"] == "DELETED":
ro_vim_item_update["vim_id"] = None
- ro_vim_item_update["vim_details"] = "Deleted externally"
+ ro_vim_item_update["vim_message"] = "Deleted externally"
else:
if ro_task["vim_info"]["vim_details"] != vim_info["vim_info"]:
ro_vim_item_update["vim_details"] = vim_info["vim_info"]
ro_task["target_id"],
vim_id,
ro_vim_item_update.get("vim_status"),
- ro_vim_item_update.get("vim_details")
+ ro_vim_item_update.get("vim_message")
if ro_vim_item_update.get("vim_status") != "ACTIVE"
else "",
)
ro_vim_item_update_ok = {
"vim_status": "DELETED",
"created": False,
- "vim_details": "DELETED",
+ "vim_message": "DELETED",
"vim_id": None,
}
net_vim_id, ro_task["vim_info"]["created_items"]
)
except vimconn.VimConnNotFoundException:
- ro_vim_item_update_ok["vim_details"] = "already deleted"
+ ro_vim_item_update_ok["vim_message"] = "already deleted"
except vimconn.VimConnException as e:
self.logger.error(
"ro_task={} vim={} del-net={}: {}".format(
)
ro_vim_item_update = {
"vim_status": "VIM_ERROR",
- "vim_details": "Error while deleting: {}".format(e),
+ "vim_message": "Error while deleting: {}".format(e),
}
return "FAILED", ro_vim_item_update
task_id,
ro_task["target_id"],
net_vim_id,
- ro_vim_item_update_ok.get("vim_details", ""),
+ ro_vim_item_update_ok.get("vim_message", ""),
)
)
if params_copy["flavor_id"].startswith("TASK-"):
params_copy["flavor_id"] = task_depends[params_copy["flavor_id"]]
+ affinity_group_list = params_copy["affinity_group_list"]
+ for affinity_group in affinity_group_list:
+ # change task_id into affinity_group_id
+ if "affinity_group_id" in affinity_group and affinity_group[
+ "affinity_group_id"
+ ].startswith("TASK-"):
+ affinity_group_id = task_depends[
+ affinity_group["affinity_group_id"]
+ ]
+
+ if not affinity_group_id:
+ raise NsWorkerException(
+ "found for {}".format(affinity_group["affinity_group_id"])
+ )
+
+ affinity_group["affinity_group_id"] = affinity_group_id
+
vim_vm_id, created_items = target_vim.new_vminstance(**params_copy)
interfaces = [iface["vim_id"] for iface in params_copy["net_list"]]
"created": created,
"created_items": created_items,
"vim_details": None,
+ "vim_message": None,
"interfaces_vim_ids": interfaces,
"interfaces": [],
+ "interfaces_backup": [],
}
self.logger.debug(
"task={} {} new-vm={} created={}".format(
ro_vim_item_update = {
"vim_status": "VIM_ERROR",
"created": created,
- "vim_details": str(e),
+ "vim_message": str(e),
}
return "FAILED", ro_vim_item_update
ro_vim_item_update_ok = {
"vim_status": "DELETED",
"created": False,
- "vim_details": "DELETED",
+ "vim_message": "DELETED",
"vim_id": None,
}
try:
+ self.logger.debug(
+ "delete_vminstance: vm_vim_id={} created_items={}".format(
+ vm_vim_id, ro_task["vim_info"]["created_items"]
+ )
+ )
if vm_vim_id or ro_task["vim_info"]["created_items"]:
target_vim = self.my_vims[ro_task["target_id"]]
target_vim.delete_vminstance(
- vm_vim_id, ro_task["vim_info"]["created_items"]
+ vm_vim_id,
+ ro_task["vim_info"]["created_items"],
+ ro_task["vim_info"].get("volumes_to_hold", []),
)
except vimconn.VimConnNotFoundException:
- ro_vim_item_update_ok["vim_details"] = "already deleted"
+ ro_vim_item_update_ok["vim_message"] = "already deleted"
except vimconn.VimConnException as e:
self.logger.error(
"ro_task={} vim={} del-vm={}: {}".format(
)
ro_vim_item_update = {
"vim_status": "VIM_ERROR",
- "vim_details": "Error while deleting: {}".format(e),
+ "vim_message": "Error while deleting: {}".format(e),
}
return "FAILED", ro_vim_item_update
task_id,
ro_task["target_id"],
vm_vim_id,
- ro_vim_item_update_ok.get("vim_details", ""),
+ ro_vim_item_update_ok.get("vim_message", ""),
)
)
ro_vim_item_update["vim_name"] = vim_info.get("name")
if vim_info["status"] in ("ERROR", "VIM_ERROR"):
- if ro_task["vim_info"]["vim_details"] != vim_info.get("error_msg"):
- ro_vim_item_update["vim_details"] = vim_info.get("error_msg")
+ if ro_task["vim_info"]["vim_message"] != vim_info.get("error_msg"):
+ ro_vim_item_update["vim_message"] = vim_info.get("error_msg")
elif vim_info["status"] == "DELETED":
ro_vim_item_update["vim_id"] = None
- ro_vim_item_update["vim_details"] = "Deleted externally"
+ ro_vim_item_update["vim_message"] = "Deleted externally"
else:
if ro_task["vim_info"]["vim_details"] != vim_info["vim_info"]:
ro_vim_item_update["vim_details"] = vim_info["vim_info"]
ro_task["target_id"],
vim_id,
ro_vim_item_update.get("vim_status"),
- ro_vim_item_update.get("vim_details")
+ ro_vim_item_update.get("vim_message")
if ro_vim_item_update.get("vim_status") != "ACTIVE"
else "",
)
except (vimconn.VimConnException, NsWorkerException) as e:
retries += 1
+ self.logger.debug(traceback.format_exc())
if retries < self.max_retries_inject_ssh_key:
return (
"BUILD",
self.logger.error(
"task={} {} inject-ssh-key: {}".format(task_id, ro_task["target_id"], e)
)
- ro_vim_item_update = {"vim_details": str(e)}
+ ro_vim_item_update = {"vim_message": str(e)}
return "FAILED", ro_vim_item_update, db_task_update
)
elif len(vim_images) > 1:
raise NsWorkerException(
- "More than one network found with this criteria: '{}'".format(
+ "More than one image found with this criteria: '{}'".format(
task["find_params"]
)
)
"created": created,
"created_items": created_items,
"vim_details": None,
+ "vim_message": None,
}
self.logger.debug(
"task={} {} new-image={} created={}".format(
ro_vim_item_update = {
"vim_status": "VIM_ERROR",
"created": created,
- "vim_details": str(e),
+ "vim_message": str(e),
}
return "FAILED", ro_vim_item_update
ro_vim_item_update_ok = {
"vim_status": "DELETED",
"created": False,
- "vim_details": "DELETED",
+ "vim_message": "DELETED",
"vim_id": None,
}
target_vim = self.my_vims[ro_task["target_id"]]
target_vim.delete_flavor(flavor_vim_id)
except vimconn.VimConnNotFoundException:
- ro_vim_item_update_ok["vim_details"] = "already deleted"
+ ro_vim_item_update_ok["vim_message"] = "already deleted"
except vimconn.VimConnException as e:
self.logger.error(
"ro_task={} vim={} del-flavor={}: {}".format(
)
ro_vim_item_update = {
"vim_status": "VIM_ERROR",
- "vim_details": "Error while deleting: {}".format(e),
+ "vim_message": "Error while deleting: {}".format(e),
}
return "FAILED", ro_vim_item_update
task_id,
ro_task["target_id"],
flavor_vim_id,
- ro_vim_item_update_ok.get("vim_details", ""),
+ ro_vim_item_update_ok.get("vim_message", ""),
)
)
"created": created,
"created_items": created_items,
"vim_details": None,
+ "vim_message": None,
}
self.logger.debug(
"task={} {} new-flavor={} created={}".format(
ro_vim_item_update = {
"vim_status": "VIM_ERROR",
"created": created,
- "vim_details": str(e),
+ "vim_message": str(e),
+ }
+
+ return "FAILED", ro_vim_item_update
+
+
+class VimInteractionAffinityGroup(VimInteractionBase):
+ def delete(self, ro_task, task_index):
+ task = ro_task["tasks"][task_index]
+ task_id = task["task_id"]
+ affinity_group_vim_id = ro_task["vim_info"]["vim_id"]
+ ro_vim_item_update_ok = {
+ "vim_status": "DELETED",
+ "created": False,
+ "vim_message": "DELETED",
+ "vim_id": None,
+ }
+
+ try:
+ if affinity_group_vim_id:
+ target_vim = self.my_vims[ro_task["target_id"]]
+ target_vim.delete_affinity_group(affinity_group_vim_id)
+ except vimconn.VimConnNotFoundException:
+ ro_vim_item_update_ok["vim_message"] = "already deleted"
+ except vimconn.VimConnException as e:
+ self.logger.error(
+ "ro_task={} vim={} del-affinity-or-anti-affinity-group={}: {}".format(
+ ro_task["_id"], ro_task["target_id"], affinity_group_vim_id, e
+ )
+ )
+ ro_vim_item_update = {
+ "vim_status": "VIM_ERROR",
+ "vim_message": "Error while deleting: {}".format(e),
+ }
+
+ return "FAILED", ro_vim_item_update
+
+ self.logger.debug(
+ "task={} {} del-affinity-or-anti-affinity-group={} {}".format(
+ task_id,
+ ro_task["target_id"],
+ affinity_group_vim_id,
+ ro_vim_item_update_ok.get("vim_message", ""),
+ )
+ )
+
+ return "DONE", ro_vim_item_update_ok
+
+ def new(self, ro_task, task_index, task_depends):
+ task = ro_task["tasks"][task_index]
+ task_id = task["task_id"]
+ created = False
+ created_items = {}
+ target_vim = self.my_vims[ro_task["target_id"]]
+
+ try:
+ affinity_group_vim_id = None
+ affinity_group_data = None
+
+ if task.get("params"):
+ affinity_group_data = task["params"].get("affinity_group_data")
+
+ if affinity_group_data and affinity_group_data.get("vim-affinity-group-id"):
+ try:
+ param_affinity_group_id = task["params"]["affinity_group_data"].get(
+ "vim-affinity-group-id"
+ )
+ affinity_group_vim_id = target_vim.get_affinity_group(
+ param_affinity_group_id
+ ).get("id")
+ except vimconn.VimConnNotFoundException:
+ self.logger.error(
+ "task={} {} new-affinity-or-anti-affinity-group. Provided VIM Affinity Group ID {}"
+ "could not be found at VIM. Creating a new one.".format(
+ task_id, ro_task["target_id"], param_affinity_group_id
+ )
+ )
+
+ if not affinity_group_vim_id and affinity_group_data:
+ affinity_group_vim_id = target_vim.new_affinity_group(
+ affinity_group_data
+ )
+ created = True
+
+ ro_vim_item_update = {
+ "vim_id": affinity_group_vim_id,
+ "vim_status": "DONE",
+ "created": created,
+ "created_items": created_items,
+ "vim_details": None,
+ "vim_message": None,
+ }
+ self.logger.debug(
+ "task={} {} new-affinity-or-anti-affinity-group={} created={}".format(
+ task_id, ro_task["target_id"], affinity_group_vim_id, created
+ )
+ )
+
+ return "DONE", ro_vim_item_update
+ except (vimconn.VimConnException, NsWorkerException) as e:
+ self.logger.error(
+ "task={} vim={} new-affinity-or-anti-affinity-group:"
+ " {}".format(task_id, ro_task["target_id"], e)
+ )
+ ro_vim_item_update = {
+ "vim_status": "VIM_ERROR",
+ "created": created,
+ "vim_message": str(e),
}
return "FAILED", ro_vim_item_update
"created_items": created_items,
"connected_ports": connected_ports,
"vim_details": sdn_info,
+ "vim_message": None,
"last_update": last_update,
}
ro_vim_item_update = {
"vim_status": "VIM_ERROR",
"created": created,
- "vim_details": str(e),
+ "vim_message": str(e),
}
return "FAILED", ro_vim_item_update
ro_vim_item_update_ok = {
"vim_status": "DELETED",
"created": False,
- "vim_details": "DELETED",
+ "vim_message": "DELETED",
"vim_id": None,
}
isinstance(e, sdnconn.SdnConnectorError)
and e.http_code == HTTPStatus.NOT_FOUND.value
):
- ro_vim_item_update_ok["vim_details"] = "already deleted"
+ ro_vim_item_update_ok["vim_message"] = "already deleted"
else:
self.logger.error(
"ro_task={} vim={} del-sdn-net={}: {}".format(
)
ro_vim_item_update = {
"vim_status": "VIM_ERROR",
- "vim_details": "Error while deleting: {}".format(e),
+ "vim_message": "Error while deleting: {}".format(e),
}
return "FAILED", ro_vim_item_update
task_id,
ro_task["target_id"],
sdn_vim_id,
- ro_vim_item_update_ok.get("vim_details", ""),
+ ro_vim_item_update_ok.get("vim_message", ""),
)
)
return "DONE", ro_vim_item_update_ok
+class VimInteractionMigration(VimInteractionBase):
+ def exec(self, ro_task, task_index, task_depends):
+ task = ro_task["tasks"][task_index]
+ task_id = task["task_id"]
+ db_task_update = {"retries": 0}
+ target_vim = self.my_vims[ro_task["target_id"]]
+ vim_interfaces = []
+ created = False
+ created_items = {}
+ refreshed_vim_info = {}
+
+ try:
+ if task.get("params"):
+ vim_vm_id = task["params"].get("vim_vm_id")
+ migrate_host = task["params"].get("migrate_host")
+ _, migrated_compute_node = target_vim.migrate_instance(
+ vim_vm_id, migrate_host
+ )
+
+ if migrated_compute_node:
+ # When VM is migrated, vdu["vim_info"] needs to be updated
+ vdu_old_vim_info = task["params"]["vdu_vim_info"].get(
+ ro_task["target_id"]
+ )
+
+ # Refresh VM to get new vim_info
+ vm_to_refresh_list = [vim_vm_id]
+ vim_dict = target_vim.refresh_vms_status(vm_to_refresh_list)
+ refreshed_vim_info = vim_dict[vim_vm_id]
+
+ if refreshed_vim_info.get("interfaces"):
+ for old_iface in vdu_old_vim_info.get("interfaces"):
+ iface = next(
+ (
+ iface
+ for iface in refreshed_vim_info["interfaces"]
+ if old_iface["vim_interface_id"]
+ == iface["vim_interface_id"]
+ ),
+ None,
+ )
+ vim_interfaces.append(iface)
+
+ ro_vim_item_update = {
+ "vim_id": vim_vm_id,
+ "vim_status": "ACTIVE",
+ "created": created,
+ "created_items": created_items,
+ "vim_details": None,
+ "vim_message": None,
+ }
+
+ if refreshed_vim_info and refreshed_vim_info.get("status") not in (
+ "ERROR",
+ "VIM_ERROR",
+ ):
+ ro_vim_item_update["vim_details"] = refreshed_vim_info["vim_info"]
+
+ if vim_interfaces:
+ ro_vim_item_update["interfaces"] = vim_interfaces
+
+ self.logger.debug(
+ "task={} {} vm-migration done".format(task_id, ro_task["target_id"])
+ )
+
+ return "DONE", ro_vim_item_update, db_task_update
+
+ except (vimconn.VimConnException, NsWorkerException) as e:
+ self.logger.error(
+ "task={} vim={} VM Migration:"
+ " {}".format(task_id, ro_task["target_id"], e)
+ )
+ ro_vim_item_update = {
+ "vim_status": "VIM_ERROR",
+ "created": created,
+ "vim_message": str(e),
+ }
+
+ return "FAILED", ro_vim_item_update, db_task_update
+
+
class NsWorker(threading.Thread):
REFRESH_BUILD = 5 # 5 seconds
REFRESH_ACTIVE = 60 # 1 minute
"sdn_net": VimInteractionSdnNet(
self.db, self.my_vims, self.db_vims, self.logger
),
+ "affinity-or-anti-affinity-group": VimInteractionAffinityGroup(
+ self.db, self.my_vims, self.db_vims, self.logger
+ ),
+ "migrate": VimInteractionMigration(
+ self.db, self.my_vims, self.db_vims, self.logger
+ ),
}
self.time_last_task_processed = None
# lists of tasks to delete because nsrs or vnfrs has been deleted from db
return self.plugins[name]
try:
- for v in iter_entry_points("osm_ro{}.plugins".format(type), name):
- self.plugins[name] = v.load()
+ for ep in entry_points(group="osm_ro{}.plugins".format(type), name=name):
+ self.plugins[name] = ep.load()
except Exception as e:
raise NsWorkerException("Cannot load plugin osm_{}: {}".format(name, e))
try:
while True:
+ """
+ # Log RO tasks only when loglevel is DEBUG
+ if self.logger.getEffectiveLevel() == logging.DEBUG:
+ self._log_ro_task(
+ None,
+ None,
+ None,
+ "TASK_WF",
+ "task_locked_time="
+ + str(self.task_locked_time)
+ + " "
+ + "time_last_task_processed="
+ + str(self.time_last_task_processed)
+ + " "
+ + "now="
+ + str(now),
+ )
+ """
locked = self.db.set_one(
"ro_tasks",
q_filter={
return None
+ def _get_db_all_tasks(self):
+ """
+ Read all content of table ro_tasks to log it
+ :return: None
+ """
+ try:
+ # Checking the content of the BD:
+
+ # read and return
+ ro_task = self.db.get_list("ro_tasks")
+ for rt in ro_task:
+ self._log_ro_task(rt, None, None, "TASK_WF", "GET_ALL_TASKS")
+ return ro_task
+
+ except DbException as e:
+ self.logger.error("Database exception at _get_db_all_tasks: {}".format(e))
+ except Exception as e:
+ self.logger.critical(
+ "Unexpected exception at _get_db_all_tasks: {}".format(e), exc_info=True
+ )
+
+ return None
+
+ def _log_ro_task(self, ro_task, db_ro_task_update, db_ro_task_delete, mark, event):
+ """
+ Generate a log with the following format:
+
+ Mark;Event;ro_task_id;locked_at;modified_at;created_at;to_check_at;locked_by;
+ target_id;vim_info.refresh_at;vim_info;no_of_tasks;task_status;action_id;
+ task_array_index;task_id;task_action;task_item;task_args
+
+ Example:
+
+ TASK_WF;GET_TASK;888f1864-749a-4fc2-bc1a-97c0fffd6a6f:2;1642158724.8210013;
+ 1642158640.7986135;1642158640.7986135;1642158640.7986135;b134c9494e75:0a
+ ;vim:b7ff9e24-8868-4d68-8a57-a59dc11d0327;None;{'created': False,
+ 'created_items': None, 'vim_id': None, 'vim_name': None, 'vim_status': None,
+ 'vim_details': None, 'vim_message': None, 'refresh_at': None};1;SCHEDULED;
+ 888f1864-749a-4fc2-bc1a-97c0fffd6a6f;0;888f1864-749a-4fc2-bc1a-97c0fffd6a6f:2;
+ CREATE;image;{'filter_dict': {'name': 'ubuntu-os-cloud:image-family:ubuntu-1804-lts'}}
+ """
+ try:
+ line = []
+ i = 0
+ if ro_task is not None and isinstance(ro_task, dict):
+ for t in ro_task["tasks"]:
+ line.clear()
+ line.append(mark)
+ line.append(event)
+ line.append(ro_task.get("_id", ""))
+ line.append(str(ro_task.get("locked_at", "")))
+ line.append(str(ro_task.get("modified_at", "")))
+ line.append(str(ro_task.get("created_at", "")))
+ line.append(str(ro_task.get("to_check_at", "")))
+ line.append(str(ro_task.get("locked_by", "")))
+ line.append(str(ro_task.get("target_id", "")))
+ line.append(str(ro_task.get("vim_info", {}).get("refresh_at", "")))
+ line.append(str(ro_task.get("vim_info", "")))
+ line.append(str(ro_task.get("tasks", "")))
+ if isinstance(t, dict):
+ line.append(str(t.get("status", "")))
+ line.append(str(t.get("action_id", "")))
+ line.append(str(i))
+ line.append(str(t.get("task_id", "")))
+ line.append(str(t.get("action", "")))
+ line.append(str(t.get("item", "")))
+ line.append(str(t.get("find_params", "")))
+ line.append(str(t.get("params", "")))
+ else:
+ line.extend([""] * 2)
+ line.append(str(i))
+ line.extend([""] * 5)
+
+ i += 1
+ self.logger.debug(";".join(line))
+ elif db_ro_task_update is not None and isinstance(db_ro_task_update, dict):
+ i = 0
+ while True:
+ st = "tasks.{}.status".format(i)
+ if st not in db_ro_task_update:
+ break
+ line.clear()
+ line.append(mark)
+ line.append(event)
+ line.append(db_ro_task_update.get("_id", ""))
+ line.append(str(db_ro_task_update.get("locked_at", "")))
+ line.append(str(db_ro_task_update.get("modified_at", "")))
+ line.append("")
+ line.append(str(db_ro_task_update.get("to_check_at", "")))
+ line.append(str(db_ro_task_update.get("locked_by", "")))
+ line.append("")
+ line.append(str(db_ro_task_update.get("vim_info.refresh_at", "")))
+ line.append("")
+ line.append(str(db_ro_task_update.get("vim_info", "")))
+ line.append(str(str(db_ro_task_update).count(".status")))
+ line.append(db_ro_task_update.get(st, ""))
+ line.append("")
+ line.append(str(i))
+ line.extend([""] * 3)
+ i += 1
+ self.logger.debug(";".join(line))
+
+ elif db_ro_task_delete is not None and isinstance(db_ro_task_delete, dict):
+ line.clear()
+ line.append(mark)
+ line.append(event)
+ line.append(db_ro_task_delete.get("_id", ""))
+ line.append("")
+ line.append(db_ro_task_delete.get("modified_at", ""))
+ line.extend([""] * 13)
+ self.logger.debug(";".join(line))
+
+ else:
+ line.clear()
+ line.append(mark)
+ line.append(event)
+ line.extend([""] * 16)
+ self.logger.debug(";".join(line))
+
+ except Exception as e:
+ self.logger.error("Error logging ro_task: {}".format(e))
+
def _delete_task(self, ro_task, task_index, task_depends, db_update):
"""
Determine if this task need to be done or superseded
"created_items", False
)
+ self.logger.warning("Needed delete: {}".format(needed_delete))
if my_task["status"] == "FAILED":
return None, None # TODO need to be retry??
needed_delete = False
if needed_delete:
+ self.logger.warning(
+ "Deleting ro_task={} task_index={}".format(ro_task, task_index)
+ )
return self.item2class[my_task["item"]].delete(ro_task, task_index)
else:
return "SUPERSEDED", None
exc_info=True,
)
- return "FAILED", {"vim_status": "VIM_ERROR", "vim_details": str(e)}
+ return "FAILED", {"vim_status": "VIM_ERROR", "vim_message": str(e)}
def _create_task(self, ro_task, task_index, task_depends, db_update):
"""
)
task_status = "FAILED"
- ro_vim_item_update = {"vim_status": "VIM_ERROR", "vim_details": str(e)}
+ ro_vim_item_update = {"vim_status": "VIM_ERROR", "vim_message": str(e)}
# TODO update ro_vim_item_update
return task_status, ro_vim_item_update
fail_on_empty=False,
)
+ self.logger.warning("ro_task_dependency={}".format(ro_task_dependency))
if ro_task_dependency:
- for task_index, task in ro_task_dependency["tasks"]:
+ 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))
ro_task["vim_info"]["refresh_at"] = next_refresh
try:
+ """
+ # Log RO tasks only when loglevel is DEBUG
+ if self.logger.getEffectiveLevel() == logging.DEBUG:
+ self._log_ro_task(ro_task, None, None, "TASK_WF", "GET_TASK")
+ """
# 0: get task_status_create
lock_object = None
task_status_create = None
dependency_task = dependency_ro_task["tasks"][
dependency_task_index
]
+ self.logger.warning(
+ "dependency_ro_task={} dependency_task_index={}".format(
+ dependency_ro_task, dependency_task_index
+ )
+ )
if dependency_task["status"] == "SCHEDULED":
dependency_not_completed = True
next_check_at = min(
next_check_at, dependency_ro_task["to_check_at"]
)
+ # must allow dependent task to be processed first
+ # to do this set time after last_task_processed
+ next_check_at = max(
+ self.time_last_task_processed, next_check_at
+ )
break
elif dependency_task["status"] == "FAILED":
error_text = "Cannot {} {} because depends on failed {} {} id={}): {}".format(
dependency_task["item"],
dependency_task_id,
dependency_ro_task["vim_info"].get(
- "vim_details"
+ "vim_message"
),
)
self.logger.error(
] = dependency_ro_task["vim_info"]["vim_id"]
if dependency_not_completed:
+ self.logger.warning(
+ "DEPENDENCY NOT COMPLETED {}".format(
+ dependency_ro_task["vim_info"]["vim_id"]
+ )
+ )
# TODO set at vim_info.vim_details that it is waiting
continue
task["item"]
].refresh(ro_task)
_update_refresh(new_status)
+ else:
+ # The refresh is updated to avoid set the value of "refresh_at" to
+ # default value (next_check_at = now + (24 * 60 * 60)) when status is BUILD,
+ # because it can happen that in this case the task is never processed
+ _update_refresh(task["status"])
except Exception as e:
new_status = "FAILED"
db_vim_info_update = {
"vim_status": "VIM_ERROR",
- "vim_details": str(e),
+ "vim_message": str(e),
}
if not isinstance(
db_ro_task_update["modified_at"] = now
db_ro_task_update["to_check_at"] = next_check_at
+ """
+ # Log RO tasks only when loglevel is DEBUG
+ if self.logger.getEffectiveLevel() == logging.DEBUG:
+ db_ro_task_update_log = db_ro_task_update.copy()
+ db_ro_task_update_log["_id"] = q_filter["_id"]
+ self._log_ro_task(None, db_ro_task_update_log, None, "TASK_WF", "SET_TASK")
+ """
+
if not self.db.set_one(
"ro_tasks",
update_dict=db_ro_task_update,
):
del db_ro_task_update["to_check_at"]
del q_filter["to_check_at"]
+ """
+ # Log RO tasks only when loglevel is DEBUG
+ if self.logger.getEffectiveLevel() == logging.DEBUG:
+ self._log_ro_task(
+ None,
+ db_ro_task_update_log,
+ None,
+ "TASK_WF",
+ "SET_TASK " + str(q_filter),
+ )
+ """
self.db.set_one(
"ro_tasks",
q_filter=q_filter,
path_vim_status + "." + k: v
for k, v in ro_vim_item_update.items()
if k
- in ("vim_id", "vim_details", "vim_name", "vim_status", "interfaces")
+ in (
+ "vim_id",
+ "vim_details",
+ "vim_message",
+ "vim_name",
+ "vim_status",
+ "interfaces",
+ "interfaces_backup",
+ )
}
if path_vim_status.startswith("vdur."):
).split(";")[0]
self.db.set_one(table, q_filter={"_id": _id}, update_dict=update_dict)
+
+ # If interfaces exists, it backups VDU interfaces in the DB for healing operations
+ if ro_vim_item_update.get("interfaces"):
+ search_key = path_vim_status + ".interfaces"
+ if update_dict.get(search_key):
+ interfaces_backup_update = {
+ path_vim_status + ".interfaces_backup": update_dict[search_key]
+ }
+
+ self.db.set_one(
+ table,
+ q_filter={"_id": _id},
+ update_dict=interfaces_backup_update,
+ )
+
else:
update_dict = {path_item + ".status": "DELETED"}
self.db.set_one(
if self.tasks_to_delete:
self._process_delete_db_tasks()
busy = False
+ """
+ # Log RO tasks only when loglevel is DEBUG
+ if self.logger.getEffectiveLevel() == logging.DEBUG:
+ _ = self._get_db_all_tasks()
+ """
ro_task = self._get_db_task()
if ro_task:
+ self.logger.warning("Task to process: {}".format(ro_task))
+ time.sleep(1)
self._process_pending_tasks(ro_task)
busy = True
if not busy: