| Felipe Vicens | c2033f2 | 2018-11-15 15:09:58 +0100 | [diff] [blame] | 1 | # -*- coding: utf-8 -*- |
| 2 | |
| 3 | import asyncio |
| 4 | import logging |
| 5 | import logging.handlers |
| 6 | import traceback |
| 7 | import ns |
| Felipe Vicens | 6559b4a | 2018-12-01 04:40:48 +0100 | [diff] [blame] | 8 | import ROclient |
| Felipe Vicens | c2033f2 | 2018-11-15 15:09:58 +0100 | [diff] [blame] | 9 | from lcm_utils import LcmException, LcmBase |
| 10 | from osm_common.dbbase import DbException |
| 11 | from time import time |
| Felipe Vicens | 6559b4a | 2018-12-01 04:40:48 +0100 | [diff] [blame] | 12 | from http import HTTPStatus |
| 13 | from copy import deepcopy |
| 14 | |
| Felipe Vicens | c2033f2 | 2018-11-15 15:09:58 +0100 | [diff] [blame] | 15 | |
| 16 | __author__ = "Felipe Vicens, Pol Alemany, Alfonso Tierno" |
| 17 | |
| 18 | |
| Felipe Vicens | 6559b4a | 2018-12-01 04:40:48 +0100 | [diff] [blame] | 19 | def get_iterable(in_dict, in_key): |
| 20 | """ |
| 21 | Similar to <dict>.get(), but if value is None, False, ..., An empty tuple is returned instead |
| 22 | :param in_dict: a dictionary |
| 23 | :param in_key: the key to look for at in_dict |
| 24 | :return: in_dict[in_var] or () if it is None or not present |
| 25 | """ |
| 26 | if not in_dict.get(in_key): |
| 27 | return () |
| 28 | return in_dict[in_key] |
| 29 | |
| 30 | |
| Felipe Vicens | c2033f2 | 2018-11-15 15:09:58 +0100 | [diff] [blame] | 31 | class NetsliceLcm(LcmBase): |
| 32 | |
| Felipe Vicens | 6559b4a | 2018-12-01 04:40:48 +0100 | [diff] [blame] | 33 | total_deploy_timeout = 2 * 3600 # global timeout for deployment |
| 34 | |
| Felipe Vicens | c2033f2 | 2018-11-15 15:09:58 +0100 | [diff] [blame] | 35 | def __init__(self, db, msg, fs, lcm_tasks, ro_config, vca_config, loop): |
| 36 | """ |
| 37 | Init, Connect to database, filesystem storage, and messaging |
| 38 | :param config: two level dictionary with configuration. Top level should contain 'database', 'storage', |
| 39 | :return: None |
| 40 | """ |
| 41 | # logging |
| 42 | self.logger = logging.getLogger('lcm.netslice') |
| 43 | self.loop = loop |
| 44 | self.lcm_tasks = lcm_tasks |
| 45 | self.ns = ns.NsLcm(db, msg, fs, lcm_tasks, ro_config, vca_config, loop) |
| Felipe Vicens | 6559b4a | 2018-12-01 04:40:48 +0100 | [diff] [blame] | 46 | self.ro_config = ro_config |
| Felipe Vicens | c2033f2 | 2018-11-15 15:09:58 +0100 | [diff] [blame] | 47 | |
| 48 | super().__init__(db, msg, fs, self.logger) |
| 49 | |
| Felipe Vicens | c2033f2 | 2018-11-15 15:09:58 +0100 | [diff] [blame] | 50 | async def instantiate(self, nsir_id, nsilcmop_id): |
| 51 | logging_text = "Task netslice={} instantiate={} ".format(nsir_id, nsilcmop_id) |
| 52 | self.logger.debug(logging_text + "Enter") |
| 53 | # get all needed from database |
| 54 | exc = None |
| 55 | db_nsir = None |
| 56 | db_nsilcmop = None |
| 57 | db_nsir_update = {"_admin.nsilcmop": nsilcmop_id} |
| 58 | db_nsilcmop_update = {} |
| 59 | nsilcmop_operation_state = None |
| Felipe Vicens | 6559b4a | 2018-12-01 04:40:48 +0100 | [diff] [blame] | 60 | vim_2_RO = {} |
| 61 | RO = ROclient.ROClient(self.loop, **self.ro_config) |
| 62 | start_deploy = time() |
| 63 | |
| 64 | def vim_account_2_RO(vim_account): |
| 65 | """ |
| 66 | Translate a RO vim_account from OSM vim_account params |
| 67 | :param ns_params: OSM instantiate params |
| 68 | :return: The RO ns descriptor |
| 69 | """ |
| 70 | if vim_account in vim_2_RO: |
| 71 | return vim_2_RO[vim_account] |
| 72 | |
| 73 | db_vim = self.db.get_one("vim_accounts", {"_id": vim_account}) |
| 74 | if db_vim["_admin"]["operationalState"] != "ENABLED": |
| 75 | raise LcmException("VIM={} is not available. operationalState={}".format( |
| 76 | vim_account, db_vim["_admin"]["operationalState"])) |
| 77 | RO_vim_id = db_vim["_admin"]["deployed"]["RO"] |
| 78 | vim_2_RO[vim_account] = RO_vim_id |
| 79 | return RO_vim_id |
| 80 | |
| 81 | def nsi_update_nsir(self, nsi_update_nsir, db_nsir, nsir_desc_RO): |
| 82 | """ |
| 83 | Updates database nsir with the RO info for the created vld |
| 84 | :param nsi_update_nsir: dictionary to be filled with the updated info |
| 85 | :param db_nsir: content of db_nsir. This is also modified |
| 86 | :param nsir_desc_RO: nsir descriptor from RO |
| 87 | :return: Nothing, LcmException is raised on errors |
| 88 | """ |
| 89 | |
| 90 | for vld_index, vld in enumerate(get_iterable(db_nsir, "vld")): |
| 91 | for net_RO in get_iterable(nsir_desc_RO, "nets"): |
| 92 | if vld["id"] != net_RO.get("ns_net_osm_id"): |
| 93 | continue |
| 94 | vld["vim-id"] = net_RO.get("vim_net_id") |
| 95 | vld["name"] = net_RO.get("vim_name") |
| 96 | vld["status"] = net_RO.get("status") |
| 97 | vld["status-detailed"] = net_RO.get("error_msg") |
| 98 | nsi_update_nsir["vld.{}".format(vld_index)] = vld |
| 99 | break |
| 100 | else: |
| 101 | raise LcmException("ns_update_nsir: Not found vld={} at RO info".format(vld["id"])) |
| Felipe Vicens | c2033f2 | 2018-11-15 15:09:58 +0100 | [diff] [blame] | 102 | |
| 103 | try: |
| 104 | step = "Getting nsir={} from db".format(nsir_id) |
| 105 | db_nsir = self.db.get_one("nsis", {"_id": nsir_id}) |
| 106 | step = "Getting nsilcmop={} from db".format(nsilcmop_id) |
| 107 | db_nsilcmop = self.db.get_one("nsilcmops", {"_id": nsilcmop_id}) |
| 108 | |
| 109 | # look if previous tasks is in process |
| 110 | task_name, task_dependency = self.lcm_tasks.lookfor_related("nsi", nsir_id, nsilcmop_id) |
| 111 | if task_dependency: |
| 112 | step = db_nsilcmop_update["detailed-status"] = \ |
| 113 | "Waiting for related tasks to be completed: {}".format(task_name) |
| 114 | self.logger.debug(logging_text + step) |
| 115 | self.update_db_2("nsilcmops", nsilcmop_id, db_nsilcmop_update) |
| 116 | _, pending = await asyncio.wait(task_dependency, timeout=3600) |
| 117 | if pending: |
| 118 | raise LcmException("Timeout waiting related tasks to be completed") |
| 119 | |
| 120 | # Empty list to keep track of network service records status in the netslice |
| 121 | nsir_admin = db_nsir["_admin"] |
| Felipe Vicens | 6559b4a | 2018-12-01 04:40:48 +0100 | [diff] [blame] | 122 | nsir_vlds = nsir_admin["netslice-vld"] |
| Felipe Vicens | c2033f2 | 2018-11-15 15:09:58 +0100 | [diff] [blame] | 123 | nsir_admin["nsrs-detailed-list"] = [] |
| 124 | |
| 125 | # Slice status Creating |
| 126 | db_nsir_update["detailed-status"] = "creating" |
| 127 | db_nsir_update["operational-status"] = "init" |
| 128 | self.update_db_2("nsis", nsir_id, db_nsir_update) |
| 129 | |
| Felipe Vicens | 6559b4a | 2018-12-01 04:40:48 +0100 | [diff] [blame] | 130 | # TODO: Multiple VIMs networks: datacenters |
| 131 | nets = [] |
| 132 | for netslice_vld in nsir_vlds: |
| 133 | RO_ns_params = {} |
| 134 | RO_ns_params["name"] = db_nsir["name"] |
| 135 | if netslice_vld.get("vim-network-name"): |
| 136 | if not isinstance(netslice_vld["vim-network-name"], str): |
| 137 | name = netslice_vld["vim-network-name"][netslice_vld["vimAccountId"]] |
| 138 | nets.append({"name": name, "external": False, "type": "bridge"}) |
| 139 | else: |
| 140 | nets.append({"name": netslice_vld["vim-network-name"], "external": False, "type": "bridge"}) |
| 141 | else: |
| 142 | nets.append({"name": "default", "external": False, "type": "bridge"}) |
| 143 | RO_ns_params["scenario"] = {"nets": nets} |
| 144 | RO_ns_params["datacenter"] = vim_account_2_RO(netslice_vld["vimAccountId"]) |
| 145 | |
| tierno | baa5110 | 2018-12-14 13:16:18 +0000 | [diff] [blame] | 146 | # set state to INSTANTIATED. When instantiated NBI will not delete directly |
| 147 | db_nsir_update["_admin.nsState"] = "INSTANTIATED" |
| 148 | self.update_db_2("nsis", nsir_id, db_nsir_update) |
| 149 | |
| Felipe Vicens | 6559b4a | 2018-12-01 04:40:48 +0100 | [diff] [blame] | 150 | # Crate ns at RO |
| 151 | # if present use it unless in error status |
| 152 | RO_nsir_id = db_nsir["_admin"].get("deployed", {}).get("RO", {}).get("nsir_id") |
| 153 | if RO_nsir_id: |
| 154 | try: |
| 155 | step = db_nsir_update["detailed-status"] = "Looking for existing ns at RO" |
| 156 | # self.logger.debug(logging_text + step + " RO_ns_id={}".format(RO_nsir_id)) |
| 157 | desc = await RO.show("ns", RO_nsir_id) |
| 158 | except ROclient.ROClientException as e: |
| 159 | if e.http_code != HTTPStatus.NOT_FOUND: |
| 160 | raise |
| 161 | RO_nsir_id = db_nsir_update["_admin.deployed.RO.nsir_id"] = None |
| 162 | if RO_nsir_id: |
| 163 | ns_status, ns_status_info = RO.check_ns_status(desc) |
| 164 | db_nsir_update["_admin.deployed.RO.nsir_status"] = ns_status |
| 165 | if ns_status == "ERROR": |
| 166 | step = db_nsir_update["detailed-status"] = "Deleting ns at RO. RO_ns_id={}".format(RO_nsir_id) |
| 167 | self.logger.debug(logging_text + step) |
| 168 | await RO.delete("ns", RO_nsir_id) |
| 169 | RO_nsir_id = db_nsir_update["_admin.deployed.RO.nsir_id"] = None |
| 170 | if not RO_nsir_id: |
| 171 | step = db_nsir_update["detailed-status"] = "Checking dependencies" |
| 172 | # self.logger.debug(logging_text + step) |
| 173 | # check if VIM is creating and wait look if previous tasks in process |
| 174 | for vimAccountId_unit in RO_ns_params["datacenter"]: |
| 175 | task_name, task_dependency = self.lcm_tasks.lookfor_related("vim_account", vimAccountId_unit) |
| 176 | if task_dependency: |
| 177 | step = "Waiting for related tasks to be completed: {}".format(task_name) |
| 178 | self.logger.debug(logging_text + step) |
| 179 | await asyncio.wait(task_dependency, timeout=3600) |
| 180 | |
| 181 | step = db_nsir_update["detailed-status"] = "Creating ns at RO" |
| 182 | desc = await RO.create("ns", descriptor=RO_ns_params) |
| 183 | RO_nsir_id = db_nsir_update["_admin.deployed.RO.nsir_id"] = desc["uuid"] |
| Felipe Vicens | 6559b4a | 2018-12-01 04:40:48 +0100 | [diff] [blame] | 184 | db_nsir_update["_admin.deployed.RO.nsir_status"] = "BUILD" |
| 185 | self.logger.debug(logging_text + "ns created at RO. RO_id={}".format(desc["uuid"])) |
| 186 | self.update_db_2("nsis", nsir_id, db_nsir_update) |
| 187 | |
| 188 | # wait until NS scenario for netslice-vld is ready |
| 189 | step = ns_status_detailed = detailed_status = "Waiting ns ready at RO. RO_id={}".format(RO_nsir_id) |
| 190 | detailed_status_old = None |
| 191 | self.logger.debug(logging_text + step) |
| 192 | |
| 193 | while time() <= start_deploy + self.total_deploy_timeout: |
| 194 | desc = await RO.show("ns", RO_nsir_id) |
| 195 | ns_status, ns_status_info = RO.check_ns_status(desc) |
| 196 | db_nsir_update["admin.deployed.RO.nsir_status"] = ns_status |
| 197 | db_nsir_update["admin.deployed.RO.nsr_id"] = desc.get("uuid") |
| 198 | if ns_status == "ERROR": |
| 199 | raise ROclient.ROClientException(ns_status_info) |
| 200 | elif ns_status == "BUILD": |
| 201 | detailed_status = ns_status_detailed + "; {}".format(ns_status_info) |
| 202 | elif ns_status == "ACTIVE": |
| 203 | break |
| 204 | else: |
| 205 | assert False, "ROclient.check_ns_status returns unknown {}".format(ns_status) |
| 206 | if detailed_status != detailed_status_old: |
| 207 | detailed_status_old = db_nsir_update["detailed-status"] = detailed_status |
| 208 | self.update_db_2("nsis", nsir_id, db_nsir_update) |
| 209 | await asyncio.sleep(5, loop=self.loop) |
| 210 | else: # total_deploy_timeout |
| 211 | raise ROclient.ROClientException("Timeout waiting ns to be ready") |
| 212 | |
| 213 | step = "Updating NSIR" |
| 214 | nsi_update_nsir(self, db_nsir_update, db_nsir, desc) |
| 215 | |
| Felipe Vicens | c2033f2 | 2018-11-15 15:09:58 +0100 | [diff] [blame] | 216 | # Iterate over the network services operation ids to instantiate NSs |
| 217 | # TODO: (future improvement) look another way check the tasks instead of keep asking |
| 218 | # -> https://docs.python.org/3/library/asyncio-task.html#waiting-primitives |
| 219 | # steps: declare ns_tasks, add task when terminate is called, await asyncio.wait(vca_task_list, timeout=300) |
| 220 | # ns_tasks = [] |
| 221 | nslcmop_ids = db_nsilcmop["operationParams"].get("nslcmops_ids") |
| 222 | for nslcmop_id in nslcmop_ids: |
| 223 | nslcmop = self.db.get_one("nslcmops", {"_id": nslcmop_id}) |
| 224 | nsr_id = nslcmop.get("nsInstanceId") |
| 225 | step = "Launching ns={} instantiate={} task".format(nsr_id, nslcmop) |
| 226 | task = asyncio.ensure_future(self.ns.instantiate(nsr_id, nslcmop_id)) |
| 227 | self.lcm_tasks.register("ns", nsr_id, nslcmop_id, "ns_instantiate", task) |
| 228 | |
| 229 | # Wait until Network Slice is ready |
| 230 | step = nsir_status_detailed = " Waiting nsi ready. nsi_id={}".format(nsir_id) |
| 231 | nsrs_detailed_list_old = None |
| 232 | self.logger.debug(logging_text + step) |
| 233 | |
| 234 | # TODO: substitute while for await (all task to be done or not) |
| 235 | deployment_timeout = 2 * 3600 # Two hours |
| 236 | while deployment_timeout > 0: |
| 237 | # Check ns instantiation status |
| 238 | nsi_ready = True |
| 239 | nsrs_detailed_list = [] |
| 240 | for nslcmop_item in nslcmop_ids: |
| 241 | nslcmop = self.db.get_one("nslcmops", {"_id": nslcmop_item}) |
| 242 | status = nslcmop.get("operationState") |
| 243 | # TODO: (future improvement) other possible status: ROLLING_BACK,ROLLED_BACK |
| 244 | nsrs_detailed_list.append({"nsrId": nslcmop["nsInstanceId"], "status": nslcmop["operationState"], |
| 245 | "detailed-status": |
| 246 | nsir_status_detailed + "; {}".format(nslcmop.get("detailed-status"))}) |
| 247 | if status not in ["COMPLETED", "PARTIALLY_COMPLETED", "FAILED", "FAILED_TEMP"]: |
| 248 | nsi_ready = False |
| 249 | |
| Felipe Vicens | 6559b4a | 2018-12-01 04:40:48 +0100 | [diff] [blame] | 250 | # TODO: Check admin and _admin |
| Felipe Vicens | c2033f2 | 2018-11-15 15:09:58 +0100 | [diff] [blame] | 251 | if nsrs_detailed_list != nsrs_detailed_list_old: |
| 252 | nsir_admin["nsrs-detailed-list"] = nsrs_detailed_list |
| 253 | nsrs_detailed_list_old = nsrs_detailed_list |
| 254 | db_nsir_update["_admin"] = nsir_admin |
| 255 | self.update_db_2("nsis", nsir_id, db_nsir_update) |
| 256 | |
| 257 | if nsi_ready: |
| 258 | step = "Network Slice Instance is ready. nsi_id={}".format(nsir_id) |
| 259 | for items in nsrs_detailed_list: |
| 260 | if "FAILED" in items.values(): |
| 261 | raise LcmException("Error deploying NSI: {}".format(nsir_id)) |
| 262 | break |
| 263 | |
| 264 | # TODO: future improvement due to synchronism -> await asyncio.wait(vca_task_list, timeout=300) |
| 265 | await asyncio.sleep(5, loop=self.loop) |
| 266 | deployment_timeout -= 5 |
| 267 | |
| 268 | if deployment_timeout <= 0: |
| 269 | raise LcmException("Timeout waiting nsi to be ready. nsi_id={}".format(nsir_id)) |
| 270 | |
| 271 | db_nsir_update["operational-status"] = "running" |
| 272 | db_nsir_update["detailed-status"] = "done" |
| 273 | db_nsir_update["config-status"] = "configured" |
| 274 | db_nsilcmop_update["operationState"] = nsilcmop_operation_state = "COMPLETED" |
| 275 | db_nsilcmop_update["statusEnteredTime"] = time() |
| 276 | db_nsilcmop_update["detailed-status"] = "done" |
| 277 | return |
| 278 | |
| 279 | except (LcmException, DbException) as e: |
| 280 | self.logger.error(logging_text + "Exit Exception while '{}': {}".format(step, e)) |
| 281 | exc = e |
| 282 | except asyncio.CancelledError: |
| 283 | self.logger.error(logging_text + "Cancelled Exception while '{}'".format(step)) |
| 284 | exc = "Operation was cancelled" |
| 285 | except Exception as e: |
| 286 | exc = traceback.format_exc() |
| 287 | self.logger.critical(logging_text + "Exit Exception {} while '{}': {}".format(type(e).__name__, step, e), |
| 288 | exc_info=True) |
| 289 | finally: |
| 290 | if exc: |
| 291 | if db_nsir: |
| 292 | db_nsir_update["detailed-status"] = "ERROR {}: {}".format(step, exc) |
| 293 | db_nsir_update["operational-status"] = "failed" |
| 294 | if db_nsilcmop: |
| 295 | db_nsilcmop_update["detailed-status"] = "FAILED {}: {}".format(step, exc) |
| 296 | db_nsilcmop_update["operationState"] = nsilcmop_operation_state = "FAILED" |
| 297 | db_nsilcmop_update["statusEnteredTime"] = time() |
| tierno | baa5110 | 2018-12-14 13:16:18 +0000 | [diff] [blame] | 298 | try: |
| 299 | if db_nsir: |
| 300 | db_nsir_update["_admin.nsiState"] = "INSTANTIATED" |
| 301 | db_nsir_update["_admin.nsilcmop"] = None |
| 302 | self.update_db_2("nsis", nsir_id, db_nsir_update) |
| 303 | if db_nsilcmop: |
| 304 | self.update_db_2("nsilcmops", nsilcmop_id, db_nsilcmop_update) |
| 305 | except DbException as e: |
| 306 | self.logger.error(logging_text + "Cannot update database: {}".format(e)) |
| Felipe Vicens | c2033f2 | 2018-11-15 15:09:58 +0100 | [diff] [blame] | 307 | if nsilcmop_operation_state: |
| 308 | try: |
| 309 | await self.msg.aiowrite("nsi", "instantiated", {"nsir_id": nsir_id, "nsilcmop_id": nsilcmop_id, |
| 310 | "operationState": nsilcmop_operation_state}) |
| 311 | except Exception as e: |
| 312 | self.logger.error(logging_text + "kafka_write notification Exception {}".format(e)) |
| 313 | self.logger.debug(logging_text + "Exit") |
| 314 | self.lcm_tasks.remove("nsi", nsir_id, nsilcmop_id, "nsi_instantiate") |
| 315 | |
| 316 | async def terminate(self, nsir_id, nsilcmop_id): |
| 317 | logging_text = "Task nsi={} terminate={} ".format(nsir_id, nsilcmop_id) |
| 318 | self.logger.debug(logging_text + "Enter") |
| 319 | exc = None |
| 320 | db_nsir = None |
| 321 | db_nsilcmop = None |
| 322 | db_nsir_update = {"_admin.nsilcmop": nsilcmop_id} |
| 323 | db_nsilcmop_update = {} |
| Felipe Vicens | 6559b4a | 2018-12-01 04:40:48 +0100 | [diff] [blame] | 324 | RO = ROclient.ROClient(self.loop, **self.ro_config) |
| 325 | failed_detail = [] # annotates all failed error messages |
| Felipe Vicens | c2033f2 | 2018-11-15 15:09:58 +0100 | [diff] [blame] | 326 | nsilcmop_operation_state = None |
| 327 | try: |
| 328 | step = "Getting nsir={} from db".format(nsir_id) |
| 329 | db_nsir = self.db.get_one("nsis", {"_id": nsir_id}) |
| Felipe Vicens | 6559b4a | 2018-12-01 04:40:48 +0100 | [diff] [blame] | 330 | nsir_deployed = deepcopy(db_nsir["admin"].get("deployed")) |
| Felipe Vicens | c2033f2 | 2018-11-15 15:09:58 +0100 | [diff] [blame] | 331 | step = "Getting nsilcmop={} from db".format(nsilcmop_id) |
| 332 | db_nsilcmop = self.db.get_one("nsilcmops", {"_id": nsilcmop_id}) |
| 333 | |
| 334 | # TODO: Check if makes sense check the nsiState=NOT_INSTANTIATED when terminate |
| 335 | # CASE: Instance was terminated but there is a second request to terminate the instance |
| 336 | if db_nsir["_admin"]["nsiState"] == "NOT_INSTANTIATED": |
| 337 | return |
| 338 | |
| 339 | # Slice status Terminating |
| 340 | db_nsir_update["operational-status"] = "terminating" |
| 341 | db_nsir_update["config-status"] = "terminating" |
| 342 | self.update_db_2("nsis", nsir_id, db_nsir_update) |
| 343 | |
| 344 | # look if previous tasks is in process |
| 345 | task_name, task_dependency = self.lcm_tasks.lookfor_related("nsi", nsir_id, nsilcmop_id) |
| 346 | if task_dependency: |
| 347 | step = db_nsilcmop_update["detailed-status"] = \ |
| 348 | "Waiting for related tasks to be completed: {}".format(task_name) |
| 349 | self.logger.debug(logging_text + step) |
| 350 | self.update_db_2("nsilcmops", nsilcmop_id, db_nsilcmop_update) |
| 351 | _, pending = await asyncio.wait(task_dependency, timeout=3600) |
| 352 | if pending: |
| 353 | raise LcmException("Timeout waiting related tasks to be completed") |
| 354 | |
| 355 | # Gets the list to keep track of network service records status in the netslice |
| 356 | nsir_admin = db_nsir["_admin"] |
| 357 | nsrs_detailed_list = [] |
| 358 | |
| 359 | # Iterate over the network services operation ids to terminate NSs |
| 360 | # TODO: (future improvement) look another way check the tasks instead of keep asking |
| 361 | # -> https://docs.python.org/3/library/asyncio-task.html#waiting-primitives |
| 362 | # steps: declare ns_tasks, add task when terminate is called, await asyncio.wait(vca_task_list, timeout=300) |
| 363 | # ns_tasks = [] |
| 364 | nslcmop_ids = db_nsilcmop["operationParams"].get("nslcmops_ids") |
| 365 | for nslcmop_id in nslcmop_ids: |
| 366 | nslcmop = self.db.get_one("nslcmops", {"_id": nslcmop_id}) |
| 367 | nsr_id = nslcmop["operationParams"].get("nsInstanceId") |
| 368 | task = asyncio.ensure_future(self.ns.terminate(nsr_id, nslcmop_id)) |
| 369 | self.lcm_tasks.register("ns", nsr_id, nslcmop_id, "ns_instantiate", task) |
| 370 | |
| 371 | # Wait until Network Slice is terminated |
| 372 | step = nsir_status_detailed = " Waiting nsi terminated. nsi_id={}".format(nsir_id) |
| 373 | nsrs_detailed_list_old = None |
| 374 | self.logger.debug(logging_text + step) |
| 375 | |
| 376 | termination_timeout = 2 * 3600 # Two hours |
| 377 | while termination_timeout > 0: |
| 378 | # Check ns termination status |
| 379 | nsi_ready = True |
| 380 | nsrs_detailed_list = [] |
| 381 | for nslcmop_item in nslcmop_ids: |
| 382 | nslcmop = self.db.get_one("nslcmops", {"_id": nslcmop_item}) |
| 383 | status = nslcmop["operationState"] |
| 384 | # TODO: (future improvement) other possible status: ROLLING_BACK,ROLLED_BACK |
| 385 | nsrs_detailed_list.append({"nsrId": nslcmop["nsInstanceId"], "status": nslcmop["operationState"], |
| 386 | "detailed-status": |
| 387 | nsir_status_detailed + "; {}".format(nslcmop.get("detailed-status"))}) |
| 388 | if status not in ["COMPLETED", "PARTIALLY_COMPLETED", "FAILED", "FAILED_TEMP"]: |
| 389 | nsi_ready = False |
| 390 | |
| 391 | if nsrs_detailed_list != nsrs_detailed_list_old: |
| 392 | nsir_admin["nsrs-detailed-list"] = nsrs_detailed_list |
| 393 | nsrs_detailed_list_old = nsrs_detailed_list |
| 394 | db_nsir_update["_admin"] = nsir_admin |
| 395 | self.update_db_2("nsis", nsir_id, db_nsir_update) |
| 396 | |
| 397 | if nsi_ready: |
| 398 | step = "Network Slice Instance is terminated. nsi_id={}".format(nsir_id) |
| 399 | for items in nsrs_detailed_list: |
| 400 | if "FAILED" in items.values(): |
| 401 | raise LcmException("Error terminating NSI: {}".format(nsir_id)) |
| 402 | break |
| 403 | |
| 404 | await asyncio.sleep(5, loop=self.loop) |
| 405 | termination_timeout -= 5 |
| 406 | |
| 407 | if termination_timeout <= 0: |
| 408 | raise LcmException("Timeout waiting nsi to be terminated. nsi_id={}".format(nsir_id)) |
| 409 | |
| Felipe Vicens | 6559b4a | 2018-12-01 04:40:48 +0100 | [diff] [blame] | 410 | # Delete ns |
| 411 | RO_nsir_id = RO_delete_action = None |
| 412 | if nsir_deployed and nsir_deployed.get("RO"): |
| 413 | RO_nsir_id = nsir_deployed["RO"].get("nsr_id") |
| 414 | RO_delete_action = nsir_deployed["RO"].get("nsr_delete_action_id") |
| 415 | try: |
| 416 | if RO_nsir_id: |
| 417 | step = db_nsir_update["detailed-status"] = "Deleting ns at RO" |
| 418 | db_nsilcmop_update["detailed-status"] = "Deleting ns at RO" |
| 419 | self.logger.debug(logging_text + step) |
| 420 | desc = await RO.delete("ns", RO_nsir_id) |
| 421 | RO_delete_action = desc["action_id"] |
| 422 | db_nsir_update["_admin.deployed.RO.nsr_delete_action_id"] = RO_delete_action |
| 423 | db_nsir_update["_admin.deployed.RO.nsr_id"] = None |
| 424 | db_nsir_update["_admin.deployed.RO.nsr_status"] = "DELETED" |
| 425 | if RO_delete_action: |
| 426 | # wait until NS is deleted from VIM |
| 427 | step = detailed_status = "Waiting ns deleted from VIM. RO_id={}".format(RO_nsir_id) |
| 428 | detailed_status_old = None |
| 429 | self.logger.debug(logging_text + step) |
| 430 | |
| 431 | delete_timeout = 20 * 60 # 20 minutes |
| 432 | while delete_timeout > 0: |
| 433 | desc = await RO.show("ns", item_id_name=RO_nsir_id, extra_item="action", |
| 434 | extra_item_id=RO_delete_action) |
| 435 | ns_status, ns_status_info = RO.check_action_status(desc) |
| 436 | if ns_status == "ERROR": |
| 437 | raise ROclient.ROClientException(ns_status_info) |
| 438 | elif ns_status == "BUILD": |
| 439 | detailed_status = step + "; {}".format(ns_status_info) |
| 440 | elif ns_status == "ACTIVE": |
| 441 | break |
| 442 | else: |
| 443 | assert False, "ROclient.check_action_status returns unknown {}".format(ns_status) |
| 444 | await asyncio.sleep(5, loop=self.loop) |
| 445 | delete_timeout -= 5 |
| 446 | if detailed_status != detailed_status_old: |
| 447 | detailed_status_old = db_nsilcmop_update["detailed-status"] = detailed_status |
| 448 | self.update_db_2("nslcmops", nslcmop_id, db_nsilcmop_update) |
| 449 | else: # delete_timeout <= 0: |
| 450 | raise ROclient.ROClientException("Timeout waiting ns deleted from VIM") |
| 451 | |
| 452 | except ROclient.ROClientException as e: |
| 453 | if e.http_code == 404: # not found |
| 454 | db_nsir_update["_admin.deployed.RO.nsr_id"] = None |
| 455 | db_nsir_update["_admin.deployed.RO.nsr_status"] = "DELETED" |
| 456 | self.logger.debug(logging_text + "RO_ns_id={} already deleted".format(RO_nsir_id)) |
| 457 | elif e.http_code == 409: # conflict |
| 458 | failed_detail.append("RO_ns_id={} delete conflict: {}".format(RO_nsir_id, e)) |
| 459 | self.logger.debug(logging_text + failed_detail[-1]) |
| 460 | else: |
| 461 | failed_detail.append("RO_ns_id={} delete error: {}".format(RO_nsir_id, e)) |
| 462 | self.logger.error(logging_text + failed_detail[-1]) |
| 463 | |
| Felipe Vicens | c2033f2 | 2018-11-15 15:09:58 +0100 | [diff] [blame] | 464 | db_nsir_update["operational-status"] = "terminated" |
| 465 | db_nsir_update["config-status"] = "configured" |
| 466 | db_nsir_update["detailed-status"] = "done" |
| 467 | db_nsilcmop_update["operationState"] = nsilcmop_operation_state = "COMPLETED" |
| 468 | db_nsilcmop_update["statusEnteredTime"] = time() |
| 469 | db_nsilcmop_update["detailed-status"] = "done" |
| 470 | return |
| 471 | |
| 472 | except (LcmException, DbException) as e: |
| 473 | self.logger.error(logging_text + "Exit Exception while '{}': {}".format(step, e)) |
| 474 | exc = e |
| 475 | except asyncio.CancelledError: |
| 476 | self.logger.error(logging_text + "Cancelled Exception while '{}'".format(step)) |
| 477 | exc = "Operation was cancelled" |
| 478 | except Exception as e: |
| 479 | exc = traceback.format_exc() |
| 480 | self.logger.critical(logging_text + "Exit Exception {} while '{}': {}".format(type(e).__name__, step, e), |
| 481 | exc_info=True) |
| 482 | finally: |
| 483 | if exc: |
| 484 | if db_nsir: |
| 485 | db_nsir_update["detailed-status"] = "ERROR {}: {}".format(step, exc) |
| 486 | db_nsir_update["operational-status"] = "failed" |
| 487 | if db_nsilcmop: |
| 488 | db_nsilcmop_update["detailed-status"] = "FAILED {}: {}".format(step, exc) |
| 489 | db_nsilcmop_update["operationState"] = nsilcmop_operation_state = "FAILED" |
| 490 | db_nsilcmop_update["statusEnteredTime"] = time() |
| tierno | baa5110 | 2018-12-14 13:16:18 +0000 | [diff] [blame] | 491 | try: |
| 492 | if db_nsir: |
| 493 | db_nsir_update["_admin.nsilcmop"] = None |
| 494 | db_nsir_update["_admin.nsiState"] = "TERMINATED" |
| 495 | self.update_db_2("nsis", nsir_id, db_nsir_update) |
| 496 | if db_nsilcmop: |
| 497 | self.update_db_2("nsilcmops", nsilcmop_id, db_nsilcmop_update) |
| 498 | except DbException as e: |
| 499 | self.logger.error(logging_text + "Cannot update database: {}".format(e)) |
| Felipe Vicens | c2033f2 | 2018-11-15 15:09:58 +0100 | [diff] [blame] | 500 | |
| 501 | if nsilcmop_operation_state: |
| 502 | try: |
| 503 | await self.msg.aiowrite("nsi", "terminated", {"nsir_id": nsir_id, "nsilcmop_id": nsilcmop_id, |
| 504 | "operationState": nsilcmop_operation_state}) |
| 505 | except Exception as e: |
| 506 | self.logger.error(logging_text + "kafka_write notification Exception {}".format(e)) |
| 507 | self.logger.debug(logging_text + "Exit") |
| 508 | self.lcm_tasks.remove("nsi", nsir_id, nsilcmop_id, "nsi_terminate") |