X-Git-Url: https://osm.etsi.org/gitweb/?a=blobdiff_plain;f=NG-RO%2Fosm_ng_ro%2Fns_thread.py;h=cfd36ec0dc4b11e35c935ecc13a1dc49b44dc2cc;hb=refs%2Fchanges%2F58%2F12058%2F6;hp=ab58a1f290d9be8f975fe5c1c06aaaaff3c049d2;hpb=123de18fe672551ac782aec4188150d3fe76c961;p=osm%2FRO.git diff --git a/NG-RO/osm_ng_ro/ns_thread.py b/NG-RO/osm_ng_ro/ns_thread.py index ab58a1f2..cfd36ec0 100644 --- a/NG-RO/osm_ng_ro/ns_thread.py +++ b/NG-RO/osm_ng_ro/ns_thread.py @@ -32,6 +32,7 @@ import queue from shutil import rmtree import threading import time +import traceback from unittest.mock import Mock from importlib_metadata import entry_points @@ -210,6 +211,7 @@ class VimInteractionNet(VimInteractionBase): "created": created, "created_items": created_items, "vim_details": None, + "vim_message": None, } self.logger.debug( "task={} {} new-net={} created={}".format( @@ -225,7 +227,7 @@ class VimInteractionNet(VimInteractionBase): ro_vim_item_update = { "vim_status": "VIM_ERROR", "created": created, - "vim_details": str(e), + "vim_message": str(e), } return "FAILED", ro_vim_item_update @@ -265,11 +267,11 @@ class VimInteractionNet(VimInteractionBase): 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"] @@ -281,7 +283,7 @@ class VimInteractionNet(VimInteractionBase): 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 "", ) @@ -296,7 +298,7 @@ class VimInteractionNet(VimInteractionBase): ro_vim_item_update_ok = { "vim_status": "DELETED", "created": False, - "vim_details": "DELETED", + "vim_message": "DELETED", "vim_id": None, } @@ -307,7 +309,7 @@ class VimInteractionNet(VimInteractionBase): 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( @@ -316,7 +318,7 @@ class VimInteractionNet(VimInteractionBase): ) 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 @@ -326,7 +328,7 @@ class VimInteractionNet(VimInteractionBase): 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", ""), ) ) @@ -395,6 +397,7 @@ class VimInteractionVdu(VimInteractionBase): "created": created, "created_items": created_items, "vim_details": None, + "vim_message": None, "interfaces_vim_ids": interfaces, "interfaces": [], } @@ -412,7 +415,7 @@ class VimInteractionVdu(VimInteractionBase): ro_vim_item_update = { "vim_status": "VIM_ERROR", "created": created, - "vim_details": str(e), + "vim_message": str(e), } return "FAILED", ro_vim_item_update @@ -424,18 +427,25 @@ class VimInteractionVdu(VimInteractionBase): 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( @@ -444,7 +454,7 @@ class VimInteractionVdu(VimInteractionBase): ) 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 @@ -454,7 +464,7 @@ class VimInteractionVdu(VimInteractionBase): 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", ""), ) ) @@ -542,11 +552,11 @@ class VimInteractionVdu(VimInteractionBase): 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"] @@ -558,7 +568,7 @@ class VimInteractionVdu(VimInteractionBase): 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 "", ) @@ -595,6 +605,7 @@ class VimInteractionVdu(VimInteractionBase): except (vimconn.VimConnException, NsWorkerException) as e: retries += 1 + self.logger.debug(traceback.format_exc()) if retries < self.max_retries_inject_ssh_key: return ( "BUILD", @@ -608,7 +619,7 @@ class VimInteractionVdu(VimInteractionBase): 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 @@ -647,6 +658,7 @@ class VimInteractionImage(VimInteractionBase): "created": created, "created_items": created_items, "vim_details": None, + "vim_message": None, } self.logger.debug( "task={} {} new-image={} created={}".format( @@ -662,7 +674,7 @@ class VimInteractionImage(VimInteractionBase): ro_vim_item_update = { "vim_status": "VIM_ERROR", "created": created, - "vim_details": str(e), + "vim_message": str(e), } return "FAILED", ro_vim_item_update @@ -676,7 +688,7 @@ class VimInteractionFlavor(VimInteractionBase): ro_vim_item_update_ok = { "vim_status": "DELETED", "created": False, - "vim_details": "DELETED", + "vim_message": "DELETED", "vim_id": None, } @@ -685,7 +697,7 @@ class VimInteractionFlavor(VimInteractionBase): 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( @@ -694,7 +706,7 @@ class VimInteractionFlavor(VimInteractionBase): ) 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 @@ -704,7 +716,7 @@ class VimInteractionFlavor(VimInteractionBase): 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", ""), ) ) @@ -740,6 +752,7 @@ class VimInteractionFlavor(VimInteractionBase): "created": created, "created_items": created_items, "vim_details": None, + "vim_message": None, } self.logger.debug( "task={} {} new-flavor={} created={}".format( @@ -755,7 +768,7 @@ class VimInteractionFlavor(VimInteractionBase): ro_vim_item_update = { "vim_status": "VIM_ERROR", "created": created, - "vim_details": str(e), + "vim_message": str(e), } return "FAILED", ro_vim_item_update @@ -769,7 +782,7 @@ class VimInteractionAffinityGroup(VimInteractionBase): ro_vim_item_update_ok = { "vim_status": "DELETED", "created": False, - "vim_details": "DELETED", + "vim_message": "DELETED", "vim_id": None, } @@ -778,7 +791,7 @@ class VimInteractionAffinityGroup(VimInteractionBase): 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_details"] = "already deleted" + 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( @@ -787,7 +800,7 @@ class VimInteractionAffinityGroup(VimInteractionBase): ) 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 @@ -797,7 +810,7 @@ class VimInteractionAffinityGroup(VimInteractionBase): task_id, ro_task["target_id"], affinity_group_vim_id, - ro_vim_item_update_ok.get("vim_details", ""), + ro_vim_item_update_ok.get("vim_message", ""), ) ) @@ -845,6 +858,7 @@ class VimInteractionAffinityGroup(VimInteractionBase): "created": created, "created_items": created_items, "vim_details": None, + "vim_message": None, } self.logger.debug( "task={} {} new-affinity-or-anti-affinity-group={} created={}".format( @@ -861,7 +875,7 @@ class VimInteractionAffinityGroup(VimInteractionBase): ro_vim_item_update = { "vim_status": "VIM_ERROR", "created": created, - "vim_details": str(e), + "vim_message": str(e), } return "FAILED", ro_vim_item_update @@ -1187,6 +1201,7 @@ class VimInteractionSdnNet(VimInteractionBase): "created_items": created_items, "connected_ports": connected_ports, "vim_details": sdn_info, + "vim_message": None, "last_update": last_update, } @@ -1201,7 +1216,7 @@ class VimInteractionSdnNet(VimInteractionBase): ro_vim_item_update = { "vim_status": "VIM_ERROR", "created": created, - "vim_details": str(e), + "vim_message": str(e), } return "FAILED", ro_vim_item_update @@ -1213,7 +1228,7 @@ class VimInteractionSdnNet(VimInteractionBase): ro_vim_item_update_ok = { "vim_status": "DELETED", "created": False, - "vim_details": "DELETED", + "vim_message": "DELETED", "vim_id": None, } @@ -1229,7 +1244,7 @@ class VimInteractionSdnNet(VimInteractionBase): 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( @@ -1241,7 +1256,7 @@ class VimInteractionSdnNet(VimInteractionBase): ) 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 @@ -1251,7 +1266,7 @@ class VimInteractionSdnNet(VimInteractionBase): 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", ""), ) ) @@ -1722,7 +1737,7 @@ class NsWorker(threading.Thread): 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, 'refresh_at': None};1;SCHEDULED; + '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'}} """ @@ -1818,6 +1833,7 @@ class NsWorker(threading.Thread): "created_items", False ) + self.logger.warning("Needed delete: {}".format(needed_delete)) if my_task["status"] == "FAILED": return None, None # TODO need to be retry?? @@ -1841,6 +1857,9 @@ class NsWorker(threading.Thread): 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 @@ -1853,7 +1872,7 @@ class NsWorker(threading.Thread): 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): """ @@ -1891,7 +1910,7 @@ class NsWorker(threading.Thread): ) 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 @@ -1943,8 +1962,9 @@ class NsWorker(threading.Thread): 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)) @@ -2044,6 +2064,11 @@ class NsWorker(threading.Thread): 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 @@ -2064,7 +2089,7 @@ class NsWorker(threading.Thread): dependency_task["item"], dependency_task_id, dependency_ro_task["vim_info"].get( - "vim_details" + "vim_message" ), ) self.logger.error( @@ -2080,6 +2105,11 @@ class NsWorker(threading.Thread): ] = 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 @@ -2155,7 +2185,7 @@ class NsWorker(threading.Thread): new_status = "FAILED" db_vim_info_update = { "vim_status": "VIM_ERROR", - "vim_details": str(e), + "vim_message": str(e), } if not isinstance( @@ -2289,7 +2319,14 @@ class NsWorker(threading.Thread): 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", + ) } if path_vim_status.startswith("vdur."): @@ -2482,6 +2519,8 @@ class NsWorker(threading.Thread): """ 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: