From: tierno Date: Tue, 6 Feb 2018 22:17:16 +0000 (+0100) Subject: lightweight exception capturing, logging X-Git-Tag: v3.0.3 X-Git-Url: https://osm.etsi.org/gitweb/?a=commitdiff_plain;h=806373a7dc5ccbe05c77ab3765b3127925068067;p=osm%2FRO.git lightweight exception capturing, logging Change-Id: I5933d3982775f97000e2e8b60f5fad1bff16d34a Signed-off-by: tierno --- diff --git a/lcm/Dockerfile b/lcm/Dockerfile index 15e14ef1..b603c13e 100644 --- a/lcm/Dockerfile +++ b/lcm/Dockerfile @@ -8,15 +8,15 @@ ADD . /app RUN apt-get update && apt-get install -y git python3 \ python3-pip python3-pymongo python3-yaml python3-aiohttp \ - && pip3 install aiokafka \ + && pip3 install aiokafka juju \ && mkdir -p /app/storage/kafka && mkdir -p /app/log LABEL Maintainer="alfonso.tiernosepulveda@telefonica.com" \ Description="This implements a north bound interface for OSM" \ - Version="1.0" - # Author="Alfonso Tierno" + Version="1.0" \ + Author="Alfonso Tierno" # Used for local storage VOLUME /app/storage diff --git a/lcm/osm_common/dbbase.py b/lcm/osm_common/dbbase.py index a2768ae0..b101cb43 100644 --- a/lcm/osm_common/dbbase.py +++ b/lcm/osm_common/dbbase.py @@ -1,14 +1,17 @@ +from http import HTTPStatus + +__author__ = "Alfonso Tierno " class DbException(Exception): - def __init__(self, message, http_code=404): + def __init__(self, message, http_code=HTTPStatus.NOT_FOUND): # TODO change to http.HTTPStatus instead of int that allows .value and .name self.http_code = http_code - Exception.__init__(self, message) + Exception.__init__(self, "database exception " + message) -class dbbase(object): +class DbBase(object): def __init__(self): pass diff --git a/lcm/osm_common/dbmemory.py b/lcm/osm_common/dbmemory.py index 75d1f883..cdb04828 100644 --- a/lcm/osm_common/dbmemory.py +++ b/lcm/osm_common/dbmemory.py @@ -1,14 +1,22 @@ -from dbbase import DbException, dbbase +import logging +from dbbase import DbException, DbBase from http import HTTPStatus from uuid import uuid4 from copy import deepcopy +__author__ = "Alfonso Tierno " -class dbmemory(dbbase): - def __init__(self): +class DbMemory(DbBase): + + def __init__(self, logger_name='db'): + self.logger = logging.getLogger(logger_name) self.db = {} + def db_connect(self, config): + if "logger_name" in config: + self.logger = logging.getLogger(config["logger_name"]) + @staticmethod def _format_filter(filter): return filter # TODO @@ -45,7 +53,7 @@ class dbmemory(dbbase): HTTPStatus.CONFLICT.value) l = row if not l and fail_on_empty: - raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND.value) + raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND) return deepcopy(l) except Exception as e: # TODO refine raise DbException(str(e)) @@ -70,7 +78,7 @@ class dbmemory(dbbase): break else: if fail_on_empty: - raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND.value) + raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND) return None del self.db[table][i] return {"deleted": 1} @@ -83,7 +91,7 @@ class dbmemory(dbbase): break else: if fail_on_empty: - raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND.value) + raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND) return None self.db[table][i] = deepcopy(indata) return {"upadted": 1} diff --git a/lcm/osm_common/dbmongo.py b/lcm/osm_common/dbmongo.py index 38454b3b..34e6fafb 100644 --- a/lcm/osm_common/dbmongo.py +++ b/lcm/osm_common/dbmongo.py @@ -1,20 +1,40 @@ #import pymongo -from pymongo import MongoClient -from dbbase import DbException, dbbase +import logging +from pymongo import MongoClient, errors +from dbbase import DbException, DbBase from http import HTTPStatus +from time import time, sleep -class dbmongo(dbbase): +__author__ = "Alfonso Tierno " - def __init__(self): - pass + +class DbMongo(DbBase): + conn_initial_timout = 120 + conn_timout = 10 + + def __init__(self, logger_name='db'): + self.logger = logging.getLogger(logger_name) def db_connect(self, config): try: + if "logger_name" in config: + self.logger = logging.getLogger(config["logger_name"]) self.client = MongoClient(config["host"], config["port"]) self.db = self.client[config["name"]] + if "loglevel" in config: + self.logger.setLevel(getattr(logging, config['loglevel'])) # get data to try a connection - self.db.users.find_one({"username": "admin"}) - except Exception as e: # TODO refine + now = time() + while True: + try: + self.db.users.find_one({"username": "admin"}) + return + except errors.ConnectionFailure as e: + if time() - now >= self.conn_initial_timout: + raise + self.logger.info("Waiting to database up {}".format(e)) + sleep(2) + except errors.PyMongoError as e: raise DbException(str(e)) def db_disconnect(self): @@ -62,7 +82,7 @@ class dbmongo(dbbase): return db_filter except Exception as e: raise DbException("Invalid query string filter at {}:{}. Error: {}".format(query_k, v, e), - http_code=HTTPStatus.BAD_REQUEST.value) + http_code=HTTPStatus.BAD_REQUEST) def get_list(self, table, filter={}): @@ -88,12 +108,12 @@ class dbmongo(dbbase): rows = collection.find(filter) if rows.count() == 0: if fail_on_empty: - raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND.value) + raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND) return None elif rows.count() > 1: if fail_on_more: raise DbException("Found more than one entry with filter='{}'".format(filter), - HTTPStatus.CONFLICT.value) + HTTPStatus.CONFLICT) return rows[0] except Exception as e: # TODO refine raise DbException(str(e)) @@ -114,7 +134,7 @@ class dbmongo(dbbase): rows = collection.delete_one(self._format_filter(filter)) if rows.deleted_count == 0: if fail_on_empty: - raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND.value) + raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND) return None return {"deleted": rows.deleted_count} except Exception as e: # TODO refine @@ -134,7 +154,7 @@ class dbmongo(dbbase): rows = collection.update_one(self._format_filter(filter), {"$set": update_dict}) if rows.updated_count == 0: if fail_on_empty: - raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND.value) + raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND) return None return {"deleted": rows.deleted_count} except Exception as e: # TODO refine @@ -146,7 +166,7 @@ class dbmongo(dbbase): rows = collection.replace_one({"_id": id}, indata) if rows.modified_count == 0: if fail_on_empty: - raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND.value) + raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND) return None return {"replace": rows.modified_count} except Exception as e: # TODO refine diff --git a/lcm/osm_common/fsbase.py b/lcm/osm_common/fsbase.py index 85562bdd..7b6cd0c9 100644 --- a/lcm/osm_common/fsbase.py +++ b/lcm/osm_common/fsbase.py @@ -1,13 +1,16 @@ -class FsException(Exception): +from http import HTTPStatus + +__author__ = "Alfonso Tierno " + - def __init__(self, message, http_code=404): +class FsException(Exception): + def __init__(self, message, http_code=HTTPStatus.INTERNAL_SERVER_ERROR): self.http_code = http_code - Exception.__init__(self, message) + Exception.__init__(self, "storage exception " + message) class FsBase(object): - def __init__(self): pass diff --git a/lcm/osm_common/fslocal.py b/lcm/osm_common/fslocal.py index b88475f5..10ddf735 100644 --- a/lcm/osm_common/fslocal.py +++ b/lcm/osm_common/fslocal.py @@ -1,13 +1,17 @@ import os +import logging import tarfile from http import HTTPStatus from shutil import rmtree from fsbase import FsBase, FsException +__author__ = "Alfonso Tierno " + class FsLocal(FsBase): - def __init__(self): + def __init__(self, logger_name='fs'): + self.logger = logging.getLogger(logger_name) self.path = None def get_params(self): @@ -15,6 +19,8 @@ class FsLocal(FsBase): def fs_connect(self, config): try: + if "logger_name" in config: + self.logger = logging.getLogger(config["logger_name"]) self.path = config["path"] if not self.path.endswith("/"): self.path += "/" @@ -38,7 +44,7 @@ class FsLocal(FsBase): try: os.mkdir(self.path + folder) except Exception as e: - raise FsException(str(e), http_code=HTTPStatus.INTERNAL_SERVER_ERROR.value) + raise FsException(str(e), http_code=HTTPStatus.INTERNAL_SERVER_ERROR) def file_exists(self, storage): """ @@ -105,4 +111,4 @@ class FsLocal(FsBase): if os.path.exists(f): rmtree(f) elif not ignore_non_exist: - raise FsException("File {} does not exist".format(storage), http_code=HTTPStatus.BAD_REQUEST.value) + raise FsException("File {} does not exist".format(storage), http_code=HTTPStatus.BAD_REQUEST) diff --git a/lcm/osm_common/msgbase.py b/lcm/osm_common/msgbase.py index 745df7f6..a1054146 100644 --- a/lcm/osm_common/msgbase.py +++ b/lcm/osm_common/msgbase.py @@ -1,6 +1,8 @@ from http import HTTPStatus +__author__ = "Alfonso Tierno " + class MsgException(Exception): """ @@ -14,7 +16,7 @@ class MsgException(Exception): :param http_code: type. It contains ".value" (http error code) and ".name" (http error name """ self.http_code = http_code - Exception.__init__(self, message) + Exception.__init__(self, "messaging exception " + message) class MsgBase(object): diff --git a/lcm/osm_common/msgkafka.py b/lcm/osm_common/msgkafka.py index f3507452..90c9c7ff 100644 --- a/lcm/osm_common/msgkafka.py +++ b/lcm/osm_common/msgkafka.py @@ -1,13 +1,16 @@ +import logging +import asyncio +import yaml from aiokafka import AIOKafkaConsumer from aiokafka import AIOKafkaProducer from aiokafka.errors import KafkaError from msgbase import MsgBase, MsgException -import asyncio -import yaml #import json + class MsgKafka(MsgBase): - def __init__(self): + def __init__(self, logger_name='msg'): + self.logger = logging.getLogger(logger_name) self.host = None self.port = None self.consumer = None @@ -17,6 +20,8 @@ class MsgKafka(MsgBase): def connect(self, config): try: + if "logger_name" in config: + self.logger = logging.getLogger(config["logger_name"]) self.host = config["host"] self.port = config["port"] self.topic_lst = [] diff --git a/lcm/osm_common/msglocal.py b/lcm/osm_common/msglocal.py index a380e618..238ee35f 100644 --- a/lcm/osm_common/msglocal.py +++ b/lcm/osm_common/msglocal.py @@ -1,18 +1,24 @@ +import logging import os import yaml import asyncio from msgbase import MsgBase, MsgException +__author__ = "Alfonso Tierno " -class msgLocal(MsgBase): - def __init__(self): +class MsgLocal(MsgBase): + + def __init__(self, logger_name='msg'): + self.logger = logging.getLogger(logger_name) self.path = None # create a different file for each topic self.files = {} def connect(self, config): try: + if "logger_name" in config: + self.logger = logging.getLogger(config["logger_name"]) self.path = config["path"] if not self.path.endswith("/"): self.path += "/" @@ -48,9 +54,16 @@ class msgLocal(MsgBase): def read(self, topic): try: + msg = "" if topic not in self.files: - self.files[topic] = open(self.path + topic, "r+") - msg = self.files[topic].read() + self.files[topic] = open(self.path + topic, "a+") + # ignore previous content + for line in self.files[topic]: + if not line.endswith("\n"): + msg = line + msg += self.files[topic].readline() + if not msg.endswith("\n"): + return None msg_dict = yaml.load(msg) assert len(msg_dict) == 1 for k, v in msg_dict.items(): @@ -60,16 +73,18 @@ class msgLocal(MsgBase): async def aioread(self, topic, loop=None): try: + msg = "" if not loop: loop = asyncio.get_event_loop() if topic not in self.files: - self.files[topic] = open(self.path + topic, "r+") + self.files[topic] = open(self.path + topic, "a+") # ignore previous content - while self.files[topic].read(): - pass + for line in self.files[topic]: + if not line.endswith("\n"): + msg = line while True: - msg = self.files[topic].read() - if msg: + msg += self.files[topic].readline() + if msg.endswith("\n"): break await asyncio.sleep(2, loop=loop) msg_dict = yaml.load(msg) diff --git a/lcm/osm_lcm/ROclient.py b/lcm/osm_lcm/ROclient.py index bbea5fe3..ecaa9503 100644 --- a/lcm/osm_lcm/ROclient.py +++ b/lcm/osm_lcm/ROclient.py @@ -35,6 +35,7 @@ import logging import sys from urllib.parse import quote from uuid import UUID +from copy import deepcopy __author__ = "Alfonso Tierno, Pablo Montes" __date__ = "$09-Jan-2018 09:09:48$" @@ -125,9 +126,10 @@ class ROClient: self.tenant = None self.datacenter_id_name = kwargs.get("datacenter") self.datacenter = None - self.logger = logging.getLogger(kwargs.get('logger', 'ROClient')) - if kwargs.get("debug"): - self.logger.setLevel(logging.DEBUG) + logger_name = kwargs.get('logger_name', 'ROClient') + self.logger = logging.getLogger(logger_name) + if kwargs.get("loglevel"): + self.logger.setLevel(kwargs["loglevel"]) global requests requests = kwargs.get("TODO remove") @@ -286,21 +288,24 @@ class ROClient: :param filter_by: dictionary with filtering :return: a list of dict. It can be empty. Raises ROClientException on Error, """ - if item not in self.client_to_RO: - raise ROClientException("Invalid item {}".format(item)) - if item == 'tenant': - all_tenants = None - with aiohttp.ClientSession(loop=self.loop) as session: - content = await self._list_item(session, self.client_to_RO[item], all_tenants=all_tenants, - filter_dict=filter_by) - if isinstance(content, dict): - if len(content) == 1: - for _, v in content.items(): - return v - return content.values()[0] - else: - raise ROClientException("Output not a list neither dict with len equal 1", http_code=500) - return content + try: + if item not in self.client_to_RO: + raise ROClientException("Invalid item {}".format(item)) + if item == 'tenant': + all_tenants = None + with aiohttp.ClientSession(loop=self.loop) as session: + content = await self._list_item(session, self.client_to_RO[item], all_tenants=all_tenants, + filter_dict=filter_by) + if isinstance(content, dict): + if len(content) == 1: + for _, v in content.items(): + return v + return content.values()[0] + else: + raise ROClientException("Output not a list neither dict with len equal 1", http_code=500) + return content + except aiohttp.errors.ClientOSError as e: + raise ROClientException(e, http_code=504) async def _get_item_uuid(self, session, item, item_id_name, all_tenants=False): if all_tenants: @@ -510,17 +515,20 @@ class ROClient: :param all_tenants: True if not filtering by tenant. Only allowed for admin :return: dictionary with the information or raises ROClientException on Error, NotFound, found several """ - if item not in self.client_to_RO: - raise ROClientException("Invalid item {}".format(item)) - if item == 'tenant': - all_tenants = None - - with aiohttp.ClientSession(loop=self.loop) as session: - content = await self._get_item(session, self.client_to_RO[item], item_id_name, all_tenants=all_tenants) - if len(content) == 1: - return content.values()[0] - else: - return content + try: + if item not in self.client_to_RO: + raise ROClientException("Invalid item {}".format(item)) + if item == 'tenant': + all_tenants = None + + with aiohttp.ClientSession(loop=self.loop) as session: + content = await self._get_item(session, self.client_to_RO[item], item_id_name, all_tenants=all_tenants) + if len(content) == 1: + return content.values()[0] + else: + return content + except aiohttp.errors.ClientOSError as e: + raise ROClientException(e, http_code=504) async def delete(self, item, item_id_name=None, all_tenants=False): """ @@ -530,17 +538,20 @@ class ROClient: :param all_tenants: True if not filtering by tenant. Only allowed for admin :return: dictionary with the information or raises ROClientException on Error, NotFound, found several """ - if item not in self.client_to_RO: - raise ROClientException("Invalid item {}".format(item)) - if item == 'tenant': - all_tenants = None - - with aiohttp.ClientSession(loop=self.loop) as session: - if item == 'vim': - # check that exist - item_id = await self._get_item_uuid(session, "datacenters", item_id_name, all_tenants=True) + try: + if item not in self.client_to_RO: + raise ROClientException("Invalid item {}".format(item)) + if item == 'tenant': all_tenants = None - return await self._del_item(session, self.client_to_RO[item], item_id_name, all_tenants=all_tenants) + + with aiohttp.ClientSession(loop=self.loop) as session: + if item == 'vim': + # check that exist + item_id = await self._get_item_uuid(session, "datacenters", item_id_name, all_tenants=True) + all_tenants = None + return await self._del_item(session, self.client_to_RO[item], item_id_name, all_tenants=all_tenants) + except aiohttp.errors.ClientOSError as e: + raise ROClientException(e, http_code=504) async def create(self, item, descriptor=None, descriptor_format=None, **kwargs): """ @@ -552,60 +563,67 @@ class ROClient: keys can be a dot separated list to specify elements inside dict :return: dictionary with the information or raises ROClientException on Error """ - if isinstance(descriptor, str): - descriptor = self._parse(descriptor, descriptor_format) - elif descriptor: - pass - else: - descriptor = {} - - if item not in self.client_to_RO: - raise ROClientException("Invalid item {}".format(item)) - desc, enveloped = remove_envelop(item, descriptor) - - # Override descriptor with kwargs - if kwargs: - try: - for k, v in kwargs.items(): - update_content = desc - kitem_old = None - klist = k.split(".") - for kitem in klist: - if kitem_old is not None: - update_content = update_content[kitem_old] - if isinstance(update_content, dict): - kitem_old = kitem - elif isinstance(update_content, list): - kitem_old = int(kitem) + try: + if isinstance(descriptor, str): + descriptor = self._parse(descriptor, descriptor_format) + elif descriptor: + pass + else: + descriptor = {} + + if item not in self.client_to_RO: + raise ROClientException("Invalid item {}".format(item)) + desc, enveloped = remove_envelop(item, descriptor) + + # Override descriptor with kwargs + if kwargs: + desc = deepcopy(desc) # do not modify original descriptor + try: + for k, v in kwargs.items(): + update_content = desc + kitem_old = None + klist = k.split(".") + for kitem in klist: + if kitem_old is not None: + update_content = update_content[kitem_old] + if isinstance(update_content, dict): + kitem_old = kitem + elif isinstance(update_content, list): + kitem_old = int(kitem) + else: + raise ROClientException( + "Invalid query string '{}'. Descriptor is not a list nor dict at '{}'".format(k, kitem)) + if v == "__DELETE__": + del update_content[kitem_old] else: - raise ROClientException( - "Invalid query string '{}'. Descriptor is not a list nor dict at '{}'".format(k, kitem)) - update_content[kitem_old] = v - except KeyError: - raise ROClientException( - "Invalid query string '{}'. Descriptor does not contain '{}'".format(k, kitem_old)) - except ValueError: - raise ROClientException("Invalid query string '{}'. Expected integer index list instead of '{}'".format( - k, kitem)) - except IndexError: - raise ROClientException( - "Invalid query string '{}'. Index '{}' out of range".format(k, kitem_old)) - - for mandatory in self.mandatory_for_create[item]: - if mandatory not in desc: - raise ROClientException("'{}' is mandatory parameter for {}".format(mandatory, item)) - - all_tenants = False - if item in ('tenant', 'vim'): - all_tenants = None + update_content[kitem_old] = v + except KeyError: + raise ROClientException( + "Invalid query string '{}'. Descriptor does not contain '{}'".format(k, kitem_old)) + except ValueError: + raise ROClientException("Invalid query string '{}'. Expected integer index list instead of '{}'".format( + k, kitem)) + except IndexError: + raise ROClientException( + "Invalid query string '{}'. Index '{}' out of range".format(k, kitem_old)) + + for mandatory in self.mandatory_for_create[item]: + if mandatory not in desc: + raise ROClientException("'{}' is mandatory parameter for {}".format(mandatory, item)) + + all_tenants = False + if item in ('tenant', 'vim'): + all_tenants = None - if not enveloped: - create_desc = self._create_envelop(item, desc) - else: - create_desc = descriptor + if not enveloped: + create_desc = self._create_envelop(item, desc) + else: + create_desc = descriptor - with aiohttp.ClientSession(loop=self.loop) as session: - return await self._create_item(session, self.client_to_RO[item], create_desc, all_tenants) + with aiohttp.ClientSession(loop=self.loop) as session: + return await self._create_item(session, self.client_to_RO[item], create_desc, all_tenants) + except aiohttp.errors.ClientOSError as e: + raise ROClientException(e, http_code=504) def edit_tenant(self, uuid=None, name=None, descriptor=None, descriptor_format=None, new_name=None, new_description=None): """Edit the parameters of a tenant @@ -618,24 +636,27 @@ class ROClient: Return: Raises an exception on error, not found or found several Obtain a dictionary with format {'tenant':{newtenant_info}} """ - # TODO revise - if isinstance(descriptor, str): - descriptor = self.parse(descriptor, descriptor_format) - elif descriptor: - pass - elif new_name or new_description: - descriptor={"tenant": {}} - else: - raise ROClientException("Missing descriptor") + try: + # TODO revise + if isinstance(descriptor, str): + descriptor = self.parse(descriptor, descriptor_format) + elif descriptor: + pass + elif new_name or new_description: + descriptor={"tenant": {}} + else: + raise ROClientException("Missing descriptor") - if 'tenant' not in descriptor or len(descriptor)!=1: - raise ROClientException("Descriptor must contain only one 'tenant' field") - if new_name: - descriptor['tenant']['name'] = new_name - if new_description: - descriptor['tenant']['description'] = new_description + if 'tenant' not in descriptor or len(descriptor)!=1: + raise ROClientException("Descriptor must contain only one 'tenant' field") + if new_name: + descriptor['tenant']['name'] = new_name + if new_description: + descriptor['tenant']['description'] = new_description - return self._edit_item("tenants", descriptor, uuid, name, all_tenants=None) + return self._edit_item("tenants", descriptor, uuid, name, all_tenants=None) + except aiohttp.errors.ClientOSError as e: + raise ROClientException(e, http_code=504) #DATACENTERS @@ -867,8 +888,8 @@ class ROClient: if __name__ == '__main__': RO_URL = "http://localhost:9090/openmano" - RO_TENANT = "2c94f639-cefc-4f3a-a8f9-bbab0471946a" - RO_VIM = "3e70deb6-aea1-11e7-af13-080027429aaf" + RO_TENANT = "osm" + RO_VIM = "myvim" streamformat = "%(asctime)s %(name)s %(levelname)s: %(message)s" logging.basicConfig(format=streamformat) diff --git a/lcm/osm_lcm/lcm.cfg b/lcm/osm_lcm/lcm.cfg index a44ee75c..fdc8b69f 100644 --- a/lcm/osm_lcm/lcm.cfg +++ b/lcm/osm_lcm/lcm.cfg @@ -1,10 +1,10 @@ -# TODO currently is a pure yaml format. Transform it to [ini] style with yaml inside to be coherent with other modules +# TODO currently is a pure yaml format. Consider to change it to [ini] style with yaml inside to be coherent with other modules #[global] global: - log_file: "" - log_level: DEBUG + loglevel: DEBUG + #logfile: /var/log/osm/lcm.log #[RO] RO: @@ -12,6 +12,8 @@ RO: host: localhost port: 9090 tenant: osm + loglevel: DEBUG + #logfile: /var/log/osm/lcm-ro.log #[VCA] VCA: @@ -19,6 +21,8 @@ VCA: port: 17070 user: admin secret: secret + loglevel: DEBUG + #logfile: /var/log/osm/lcm-vca.log #[database] database: @@ -28,12 +32,16 @@ database: name: osm user: user password: password + loglevel: DEBUG + #logfile: /var/log/osm/lcm-database.log #[storage] storage: driver: local # local filesystem # for local provide file path path: /app/storage + loglevel: DEBUG + #logfile: /var/log/osm/lcm-storage.log #[message] message: @@ -43,3 +51,5 @@ message: # for kafka provide host and port host: kafka port: 9092 + loglevel: DEBUG + #logfile: /var/log/osm/lcm-message.log diff --git a/lcm/osm_lcm/lcm.py b/lcm/osm_lcm/lcm.py index 9bff8c19..3b4ab601 100644 --- a/lcm/osm_lcm/lcm.py +++ b/lcm/osm_lcm/lcm.py @@ -9,17 +9,15 @@ import dbmongo import fslocal import msglocal import msgkafka +import logging +import functools from dbbase import DbException from fsbase import FsException from msgbase import MsgException from os import environ -import logging from vca import DeployApplication, RemoveApplication - -#streamformat = "%(asctime)s %(name)s %(levelname)s: %(message)s" -streamformat = "%(name)s %(levelname)s: %(message)s" -logging.basicConfig(format=streamformat, level=logging.DEBUG) - +from copy import deepcopy +from http import HTTPStatus class LcmException(Exception): pass @@ -40,16 +38,52 @@ class Lcm: # load configuration config = self.read_config_file(config_file) self.config = config - self.ro_url = "http://{}:{}/openmano".format(config["RO"]["host"], config["RO"]["port"]) - self.ro_tenant = config["RO"]["tenant"] + self.ro_config={ + "endpoint_url": "http://{}:{}/openmano".format(config["RO"]["host"], config["RO"]["port"]), + "tenant": config.get("tenant", "osm"), + "logger_name": "lcm.ROclient", + "loglevel": "ERROR", + } self.vca = config["VCA"] # TODO VCA self.loop = None + + # logging + log_format_simple = "%(asctime)s %(levelname)s %(name)s %(filename)s:%(lineno)s %(message)s" + log_formatter_simple = logging.Formatter(log_format_simple, datefmt='%Y-%m-%dT%H:%M:%S') + config["database"]["logger_name"] = "lcm.db" + config["storage"]["logger_name"] = "lcm.fs" + config["message"]["logger_name"] = "lcm.msg" + if "logfile" in config["global"]: + file_handler = logging.handlers.RotatingFileHandler(config["global"]["logfile"], + maxBytes=100e6, backupCount=9, delay=0) + file_handler.setFormatter(log_formatter_simple) + self.logger.addHandler(file_handler) + else: + str_handler = logging.StreamHandler() + str_handler.setFormatter(log_formatter_simple) + self.logger.addHandler(str_handler) + + if config["global"].get("loglevel"): + self.logger.setLevel(config["global"]["loglevel"]) + + # logging other modules + for k1, logname in {"message": "lcm.msg", "database": "lcm.db", "storage": "lcm.fs"}.items(): + config[k1]["logger_name"] = logname + logger_module = logging.getLogger(logname) + if "logfile" in config[k1]: + file_handler = logging.handlers.RotatingFileHandler(config[k1]["logfile"], + maxBytes=100e6, backupCount=9, delay=0) + file_handler.setFormatter(log_formatter_simple) + logger_module.addHandler(file_handler) + if "loglevel" in config[k1]: + logger_module.setLevel(config[k1]["loglevel"]) + try: if config["database"]["driver"] == "mongo": - self.db = dbmongo.dbmongo() + self.db = dbmongo.DbMongo() self.db.db_connect(config["database"]) elif config["database"]["driver"] == "memory": - self.db = dbmemory.dbmemory() + self.db = dbmemory.DbMemory() self.db.db_connect(config["database"]) else: raise LcmException("Invalid configuration param '{}' at '[database]':'driver'".format( @@ -63,7 +97,7 @@ class Lcm: config["storage"]["driver"])) if config["message"]["driver"] == "local": - self.msg = msglocal.msgLocal() + self.msg = msglocal.MsgLocal() self.msg.connect(config["message"]) elif config["message"]["driver"] == "kafka": self.msg = msgkafka.MsgKafka() @@ -75,92 +109,156 @@ class Lcm: self.logger.critical(str(e), exc_info=True) raise LcmException(str(e)) - # def update_nsr_db(self, nsr_id, nsr_desc): - # self.db.replace("nsrs", nsr_id, nsr_desc) - - async def create_ns(self, nsr_id): - self.logger.debug("create_ns task nsr_id={} Enter".format(nsr_id)) - db_nsr = self.db.get_one("nsrs", {"_id": nsr_id}) - nsr_lcm = { - "id": nsr_id, - "RO": {"vnfd_id": {}, "nsd_id": None, "nsr_id": None, "nsr_status": "SCHEDULED"}, - "nsr_ip": {}, - "VCA": {}, # "TODO" - } - db_nsr["_admin"]["deploy"] = nsr_lcm - db_nsr["detailed-status"] = "creating" - db_nsr["operational-status"] = "init" - - deloyment_timeout = 120 + def update_nsr_db(self, nsr_id, nsr_desc): + try: + self.db.replace("nsrs", nsr_id, nsr_desc) + except DbException as e: + self.logger.error("Updating nsr_id={}: {}".format(nsr_id, e)) + + def vca_deploy_callback(self, db_nsr, vnf_index, status, task): + # TODO study using this callback when VCA.DeployApplication success from VCAMonitor + # By the moment this callback is used only to capture exception conditions from VCA DeployApplication + nsr_id = db_nsr["_id"] + self.logger.debug("Task create_ns={} vca_deploy_callback Enter".format(nsr_id)) + try: + if task.cancelled(): + return + if task.done(): + exc = task.exception() + if exc: + nsr_lcm = db_nsr["_admin"]["deploy"] + nsr_lcm["VCA"][vnf_index]['operational-status'] = "failed" + db_nsr["detailed-status"] = "fail configuring vnf_index={} {}".format(vnf_index, exc) + db_nsr["config-status"] = "failed" + self.update_nsr_db(nsr_id, db_nsr) + else: + # TODO may be used to be called when VCA monitor status changes + pass + # except DbException as e: + # self.logger.error("Task create_ns={} vca_deploy_callback Exception {}".format(nsr_id, e)) + except Exception as e: + self.logger.critical("Task create_ns={} vca_deploy_callback Exception {}".format(nsr_id, e), exc_info=True) + + async def create_ns(self, nsr_id, order_id): + logging_text = "Task create_ns={} ".format(nsr_id) + self.logger.debug(logging_text + "Enter") + # get all needed from database + db_nsr = None + exc = None + step = "Getting nsr from db" try: + db_nsr = self.db.get_one("nsrs", {"_id": nsr_id}) nsd = db_nsr["nsd"] - RO = ROclient.ROClient(self.loop, endpoint_url=self.ro_url, tenant=self.ro_tenant, - datacenter=db_nsr["datacenter"]) - - # get vnfds, instantiate at RO + needed_vnfd = {} for c_vnf in nsd["constituent-vnfd"]: vnfd_id = c_vnf["vnfd-id-ref"] - self.logger.debug("create_ns task nsr_id={} RO vnfd={} creating".format(nsr_id, vnfd_id)) - db_nsr["detailed-status"] = "Creating vnfd {} at RO".format(vnfd_id) - vnfd = self.db.get_one("vnfds", {"id": vnfd_id}) - vnfd.pop("_admin", None) - vnfd.pop("_id", None) + if vnfd_id not in needed_vnfd: + step = "Getting vnfd={} from db".format(vnfd_id) + needed_vnfd[vnfd_id] = self.db.get_one("vnfds", {"id": vnfd_id}) + + nsr_lcm = { + "id": nsr_id, + "RO": {"vnfd_id": {}, "nsd_id": None, "nsr_id": None, "nsr_status": "SCHEDULED"}, + "nsr_ip": {}, + "VCA": {}, + } + db_nsr["_admin"]["deploy"] = nsr_lcm + db_nsr["detailed-status"] = "creating" + db_nsr["operational-status"] = "init" + + deloyment_timeout = 120 + + RO = ROclient.ROClient(self.loop, datacenter=db_nsr["datacenter"], **self.ro_config) + + # get vnfds, instantiate at RO + for vnfd_id, vnfd in needed_vnfd.items(): + step = db_nsr["detailed-status"] = "Creating vnfd={} at RO".format(vnfd_id) + self.logger.debug(logging_text + step) + vnfd_id_RO = nsr_id + "." + vnfd_id[:200] # look if present - vnfd_list = await RO.get_list("vnfd", filter_by={"osm_id": vnfd_id}) + vnfd_list = await RO.get_list("vnfd", filter_by={"osm_id": vnfd_id_RO}) if vnfd_list: nsr_lcm["RO"]["vnfd_id"][vnfd_id] = vnfd_list[0]["uuid"] - self.logger.debug("create_ns task nsr_id={} RO vnfd={} exist. Using RO_id={}".format( - nsr_id, vnfd_id, vnfd_list[0]["uuid"])) + self.logger.debug(logging_text + "RO vnfd={} exist. Using RO_id={}".format( + vnfd_id, vnfd_list[0]["uuid"])) else: - desc = await RO.create("vnfd", descriptor=vnfd) + vnfd_RO = deepcopy(vnfd) + vnfd_RO.pop("_id", None) + vnfd_RO.pop("_admin", None) + vnfd_RO["id"] = vnfd_id_RO + desc = await RO.create("vnfd", descriptor=vnfd_RO) nsr_lcm["RO"]["vnfd_id"][vnfd_id] = desc["uuid"] - self.db.replace("nsrs", nsr_id, db_nsr) - - # db_new("vnfr", vnfr) - # db_update("ns_request", nsr_id, ns_request) + self.update_nsr_db(nsr_id, db_nsr) # create nsd at RO - nsd_id = db_nsr["nsd"]["id"] - self.logger.debug("create_ns task nsr_id={} RO nsd={} creating".format(nsr_id, nsd_id)) - db_nsr["detailed-status"] = "Creating nsd {} at RO".format(nsd_id) - nsd = self.db.get_one("nsds", {"id": nsd_id}) - nsd.pop("_admin", None) - nsd.pop("_id", None) - - nsd_list = await RO.get_list("nsd", filter_by={"osm_id": nsd_id}) + nsd_id = nsd["id"] + step = db_nsr["detailed-status"] = "Creating nsd={} at RO".format(nsd_id) + self.logger.debug(logging_text + step) + + nsd_id_RO = nsd_id + "." + nsd_id[:200] + nsd_list = await RO.get_list("nsd", filter_by={"osm_id": nsd_id_RO}) if nsd_list: nsr_lcm["RO"]["nsd_id"] = nsd_list[0]["uuid"] - self.logger.debug("create_ns task nsr_id={} RO nsd={} exist. Using RO_id={}".format( - nsr_id, nsd_id, nsd_list[0]["uuid"])) + self.logger.debug(logging_text + "RO nsd={} exist. Using RO_id={}".format( + nsd_id, nsd_list[0]["uuid"])) else: - desc = await RO.create("nsd", descriptor=nsd) + nsd_RO = deepcopy(nsd) + nsd_RO["id"] = nsd_id_RO + nsd_RO.pop("_id", None) + nsd_RO.pop("_admin", None) + for c_vnf in nsd_RO["constituent-vnfd"]: + vnfd_id = c_vnf["vnfd-id-ref"] + c_vnf["vnfd-id-ref"] = nsr_id + "." + vnfd_id[:200] + desc = await RO.create("nsd", descriptor=nsd_RO) nsr_lcm["RO"]["nsd_id"] = desc["uuid"] - self.db.replace("nsrs", nsr_id, db_nsr) + self.update_nsr_db(nsr_id, db_nsr) # Crate ns at RO - self.logger.debug("create_ns task nsr_id={} RO ns creating".format(nsr_id)) - db_nsr["detailed-status"] = "Creating ns at RO" - desc = await RO.create("ns", name=db_nsr["name"], datacenter=db_nsr["datacenter"], - scenario=nsr_lcm["RO"]["nsd_id"]) - RO_nsr_id = desc["uuid"] - nsr_lcm["RO"]["nsr_id"] = RO_nsr_id - nsr_lcm["RO"]["nsr_status"] = "BUILD" - self.db.replace("nsrs", nsr_id, db_nsr) + # if present use it unless in error status + RO_nsr_id = nsr_lcm["RO"].get("nsr_id") + if RO_nsr_id: + try: + step = db_nsr["detailed-status"] = "Looking for existing ns at RO" + self.logger.debug(logging_text + step + " RO_ns_id={}".format(RO_nsr_id)) + desc = await RO.show("ns", RO_nsr_id) + except ROclient.ROClientException as e: + if e.http_code != HTTPStatus.NOT_FOUND: + raise + RO_nsr_id = nsr_lcm["RO"]["nsr_id"] = None + if RO_nsr_id: + ns_status, ns_status_info = RO.check_ns_status(desc) + nsr_lcm["RO"]["nsr_status"] = ns_status + if ns_status == "ERROR": + step = db_nsr["detailed-status"] = "Deleting ns at RO" + self.logger.debug(logging_text + step + " RO_ns_id={}".format(RO_nsr_id)) + await RO.delete("ns", RO_nsr_id) + RO_nsr_id = nsr_lcm["RO"]["nsr_id"] = None + + if not RO_nsr_id: + step = db_nsr["detailed-status"] = "Creating ns at RO" + self.logger.debug(logging_text + step) + + desc = await RO.create("ns", name=db_nsr["name"], datacenter=db_nsr["datacenter"], + scenario=nsr_lcm["RO"]["nsd_id"]) + RO_nsr_id = nsr_lcm["RO"]["nsr_id"] = desc["uuid"] + nsr_lcm["RO"]["nsr_status"] = "BUILD" + self.update_nsr_db(nsr_id, db_nsr) # wait until NS is ready - self.logger.debug("create_ns task nsr_id={} RO ns_id={} waiting to be ready".format(nsr_id, RO_nsr_id)) + step = ns_status_detailed = "Waiting ns ready at RO" + db_nsr["detailed-status"] = ns_status_detailed + self.logger.debug(logging_text + step + " RO_ns_id={}".format(RO_nsr_id)) deloyment_timeout = 600 while deloyment_timeout > 0: - ns_status_detailed = "Waiting ns ready at RO" - db_nsr["detailed-status"] = ns_status_detailed desc = await RO.show("ns", RO_nsr_id) ns_status, ns_status_info = RO.check_ns_status(desc) nsr_lcm["RO"]["nsr_status"] = ns_status if ns_status == "ERROR": raise ROclient.ROClientException(ns_status_info) elif ns_status == "BUILD": - db_nsr["detailed-status"] = ns_status_detailed + "; nsr_id: '{}', {}".format(nsr_id, ns_status_info) + db_nsr["detailed-status"] = ns_status_detailed + "; {}".format(ns_status_info) + self.update_nsr_db(nsr_id, db_nsr) elif ns_status == "ACTIVE": nsr_lcm["nsr_ip"] = RO.get_ns_vnf_ip(desc) break @@ -170,20 +268,20 @@ class Lcm: await asyncio.sleep(5, loop=self.loop) deloyment_timeout -= 5 if deloyment_timeout <= 0: - raise ROclient.ROClientException("Timeot wating ns to be ready") + raise ROclient.ROClientException("Timeout waiting ns to be ready") db_nsr["detailed-status"] = "Configuring vnfr" - self.db.replace("nsrs", nsr_id, db_nsr) + self.update_nsr_db(nsr_id, db_nsr) - #for nsd in nsr_lcm["descriptors"]["nsd"]: - - self.logger.debug("create_ns task nsr_id={} VCA look for".format(nsr_id)) + vnfd_to_config = 0 + step = "Looking for needed vnfd to configure" + self.logger.debug(logging_text + step) for c_vnf in nsd["constituent-vnfd"]: vnfd_id = c_vnf["vnfd-id-ref"] - vnfd_index = str(c_vnf["member-vnf-index"]) - vnfd = self.db.get_one("vnfds", {"id": vnfd_id}) - db_nsr["config-status"] = "config_not_needed" + vnf_index = str(c_vnf["member-vnf-index"]) + vnfd = needed_vnfd[vnfd_id] if vnfd.get("vnf-configuration") and vnfd["vnf-configuration"].get("juju"): - db_nsr["config-status"] = "configuring" + nsr_lcm["VCA"][vnf_index] = {} + vnfd_to_config += 1 proxy_charm = vnfd["vnf-configuration"]["juju"]["charm"] # Note: The charm needs to exist on disk at the location @@ -201,124 +299,139 @@ class Lcm: self.db, db_nsr, vnfd, - vnfd_index, + vnf_index, charm_path, ) ) - - db_nsr["detailed-status"] = "Done" + task.add_done_callback(functools.partial(self.vca_deploy_callback, db_nsr, vnf_index, None)) + self.lcm_tasks[nsr_id][order_id]["create_charm:" + vnf_index] = task + db_nsr["config-status"] = "configuring" if vnfd_to_config else "configured" + db_nsr["detailed-status"] = "Configuring 1/{}".format(vnfd_to_config) if vnfd_to_config else "done" db_nsr["operational-status"] = "running" - self.db.replace("nsrs", nsr_id, db_nsr) + self.update_nsr_db(nsr_id, db_nsr) self.logger.debug("create_ns task nsr_id={} Exit Ok".format(nsr_id)) return nsr_lcm - except (ROclient.ROClientException, Exception) as e: - db_nsr["operational-status"] = "failed" - db_nsr["detailed-status"] += ": ERROR {}".format(e) - self.db.replace("nsrs", nsr_id, db_nsr) - self.logger.debug( - "create_ns nsr_id={} Exit Exception on '{}': {}".format(nsr_id, db_nsr["detailed-status"], e), - exc_info=True) - - async def delete_ns(self, nsr_id): - self.logger.debug("delete_ns task nsr_id={}, Delete_ns task nsr_id={} Enter".format(nsr_id, nsr_id)) - db_nsr = self.db.get_one("nsrs", {"_id": nsr_id}) - nsr_lcm = db_nsr["_admin"]["deploy"] - - db_nsr["operational-status"] = "terminate" - db_nsr["config-status"] = "terminate" - db_nsr["detailed-status"] = "Deleting charms" - self.db.replace("nsrs", nsr_id, db_nsr) - + except (ROclient.ROClientException, DbException) as e: + self.logger.error(logging_text + "Exit Exception {}".format(e)) + exc = e + except Exception as e: + self.logger.critical(logging_text + "Exit Exception {}".format(e), exc_info=True) + exc = e + finally: + if exc and db_nsr: + db_nsr["detailed-status"] = "ERROR {}: {}".format(step , exc) + db_nsr["operational-status"] = "failed" + self.update_nsr_db(nsr_id, db_nsr) + + async def delete_ns(self, nsr_id, order_id): + logging_text = "Task delete_ns={} ".format(nsr_id) + self.logger.debug(logging_text + "Enter") + db_nsr = None + exc = None + step = "Getting nsr from db" try: - self.logger.debug("Deleting charms") + db_nsr = self.db.get_one("nsrs", {"_id": nsr_id}) nsd = db_nsr["nsd"] - for c_vnf in nsd["constituent-vnfd"]: - vnfd_id = c_vnf["vnfd-id-ref"] - vnfd_index = str(c_vnf["member-vnf-index"]) - vnfd = self.db.get_one("vnfds", {"id": vnfd_id}) - if vnfd.get("vnf-configuration") and vnfd["vnf-configuration"].get("juju"): - asyncio.ensure_future( - RemoveApplication( - self.config['VCA'], - self.db, - db_nsr, - vnfd, - vnfd_index, - ) - ) - except Exception as e: - self.logger.debug("Failed while deleting charms: {}".format(e)) - # remove from RO - - RO = ROclient.ROClient(self.loop, endpoint_url=self.ro_url, tenant=self.ro_tenant, - datacenter=db_nsr["datacenter"]) - # Delete ns - RO_nsr_id = nsr_lcm["RO"]["nsr_id"] - if RO_nsr_id: + nsr_lcm = db_nsr["_admin"]["deploy"] + + db_nsr["operational-status"] = "terminate" + db_nsr["config-status"] = "terminate" + db_nsr["detailed-status"] = "Deleting charms" + self.update_nsr_db(nsr_id, db_nsr) + try: - db_nsr["detailed-status"] = "Deleting ns at RO" - desc = await RO.delete("ns", RO_nsr_id) - self.logger.debug("delete_ns task nsr_id={} RO ns={} deleted".format(nsr_id, RO_nsr_id)) - nsr_lcm["RO"]["nsr_id"] = None - nsr_lcm["RO"]["nsr_status"] = "DELETED" - except ROclient.ROClientException as e: - if e.http_code == 404: # not found + step = db_nsr["detailed-status"] = "Deleting charms" + self.logger.debug(logging_text + step) + for vnf_index, deploy_info in nsr_lcm["VCA"].items(): + if deploy_info and deploy_info.get("appliation"): + task = asyncio.ensure_future( + RemoveApplication( + self.config['VCA'], + self.db, + db_nsr, + vnf_index, + ) + ) + self.lcm_tasks[nsr_id][order_id]["delete_charm:" + vnf_index] = task + except Exception as e: + self.logger.debug(logging_text + "Failed while deleting charms: {}".format(e)) + # remove from RO + + RO = ROclient.ROClient(self.loop, datacenter=db_nsr["datacenter"], **self.ro_config) + # Delete ns + RO_nsr_id = nsr_lcm["RO"]["nsr_id"] + if RO_nsr_id: + try: + step = db_nsr["detailed-status"] = "Deleting ns at RO" + self.logger.debug(logging_text + step) + desc = await RO.delete("ns", RO_nsr_id) nsr_lcm["RO"]["nsr_id"] = None nsr_lcm["RO"]["nsr_status"] = "DELETED" - self.logger.debug("delete_ns task nsr_id={} RO ns={} already deleted".format(nsr_id, RO_nsr_id)) - elif e.http_code == 409: #conflict - self.logger.debug("delete_ns task nsr_id={} RO ns={} delete conflict: {}".format(nsr_id, RO_nsr_id, - e)) - else: - self.logger.error("delete_ns task nsr_id={} RO ns={} delete error: {}".format(nsr_id, RO_nsr_id, e)) - self.db.replace("nsrs", nsr_id, db_nsr) + except ROclient.ROClientException as e: + if e.http_code == 404: # not found + nsr_lcm["RO"]["nsr_id"] = None + nsr_lcm["RO"]["nsr_status"] = "DELETED" + self.logger.debug(logging_text + "RO_ns_id={} already deleted".format(RO_nsr_id)) + elif e.http_code == 409: #conflict + self.logger.debug(logging_text + "RO_ns_id={} delete conflict: {}".format(RO_nsr_id, e)) + else: + self.logger.error(logging_text + "RO_ns_id={} delete error: {}".format(RO_nsr_id, e)) + self.update_nsr_db(nsr_id, db_nsr) - # Delete nsd - RO_nsd_id = nsr_lcm["RO"]["nsd_id"] - if RO_nsd_id: - try: - db_nsr["detailed-status"] = "Deleting nsd at RO" - desc = await RO.delete("nsd", RO_nsd_id) - self.logger.debug("delete_ns task nsr_id={} RO nsd={} deleted".format(nsr_id, RO_nsd_id)) - nsr_lcm["RO"]["nsd_id"] = None - except ROclient.ROClientException as e: - if e.http_code == 404: # not found + # Delete nsd + RO_nsd_id = nsr_lcm["RO"]["nsd_id"] + if RO_nsd_id: + try: + step = db_nsr["detailed-status"] = "Deleting nsd at RO" + desc = await RO.delete("nsd", RO_nsd_id) + self.logger.debug(logging_text + "RO_nsd_id={} deleted".format(RO_nsd_id)) nsr_lcm["RO"]["nsd_id"] = None - self.logger.debug("delete_ns task nsr_id={} RO nsd={} already deleted".format(nsr_id, RO_nsd_id)) - elif e.http_code == 409: #conflict - self.logger.debug("delete_ns task nsr_id={} RO nsd={} delete conflict: {}".format(nsr_id, RO_nsd_id, - e)) - else: - self.logger.error("delete_ns task nsr_id={} RO nsd={} delete error: {}".format(nsr_id, RO_nsd_id, - e)) - self.db.replace("nsrs", nsr_id, db_nsr) + except ROclient.ROClientException as e: + if e.http_code == 404: # not found + nsr_lcm["RO"]["nsd_id"] = None + self.logger.debug(logging_text + "RO_nsd_id={} already deleted".format(RO_nsd_id)) + elif e.http_code == 409: #conflict + self.logger.debug(logging_text + "RO_nsd_id={} delete conflict: {}".format(RO_nsd_id, e)) + else: + self.logger.error(logging_text + "RO_nsd_id={} delete error: {}".format(RO_nsd_id, e)) + self.update_nsr_db(nsr_id, db_nsr) - for vnf_id, RO_vnfd_id in nsr_lcm["RO"]["vnfd_id"].items(): - if not RO_vnfd_id: - continue - try: - db_nsr["detailed-status"] = "Deleting vnfd {} at RO".format(vnf_id) - desc = await RO.delete("vnfd", RO_vnfd_id) - self.logger.debug("delete_ns task nsr_id={} RO vnfd={} deleted".format(nsr_id, RO_vnfd_id)) - nsr_lcm["RO"]["vnfd_id"][vnf_id] = None - except ROclient.ROClientException as e: - if e.http_code == 404: # not found + for vnf_id, RO_vnfd_id in nsr_lcm["RO"]["vnfd_id"].items(): + if not RO_vnfd_id: + continue + try: + step = db_nsr["detailed-status"] = "Deleting vnfd={} at RO".format(vnf_id) + desc = await RO.delete("vnfd", RO_vnfd_id) + self.logger.debug(logging_text + "RO_vnfd_id={} deleted".format(RO_vnfd_id)) nsr_lcm["RO"]["vnfd_id"][vnf_id] = None - self.logger.debug("delete_ns task nsr_id={} RO vnfd={} already deleted ".format(nsr_id, RO_vnfd_id)) - elif e.http_code == 409: #conflict - self.logger.debug("delete_ns task nsr_id={} RO vnfd={} delete conflict: {}".format( - nsr_id, RO_vnfd_id, e)) - else: - self.logger.error("delete_ns task nsr_id={} RO vnfd={} delete error: {}".format( - nsr_id, RO_vnfd_id, e)) - self.db.replace("nsrs", nsr_id, db_nsr) + except ROclient.ROClientException as e: + if e.http_code == 404: # not found + nsr_lcm["RO"]["vnfd_id"][vnf_id] = None + self.logger.debug(logging_text + "RO_vnfd_id={} already deleted ".format(RO_vnfd_id)) + elif e.http_code == 409: #conflict + self.logger.debug(logging_text + "RO_vnfd_id={} delete conflict: {}".format(RO_vnfd_id, e)) + else: + self.logger.error(logging_text + "RO_vnfd_id={} delete error: {}".format(RO_vnfd_id, e)) + self.update_nsr_db(nsr_id, db_nsr) - # TODO delete from database or mark as deleted??? - db_nsr["operational-status"] = "terminated" - self.db.del_one("nsrs", {"_id": nsr_id}) - self.logger.debug("delete_ns task nsr_id={} Exit".format(nsr_id)) + # TODO delete from database or mark as deleted??? + db_nsr["operational-status"] = "terminated" + self.db.del_one("nsrs", {"_id": nsr_id}) + self.logger.debug(logging_text + "Exit") + + except (ROclient.ROClientException, DbException) as e: + self.logger.error(logging_text + "Exit Exception {}".format(e)) + exc = e + except Exception as e: + self.logger.critical(logging_text + "Exit Exception {}".format(e), exc_info=True) + exc = e + finally: + if exc and db_nsr: + db_nsr["detailed-status"] = "ERROR {}: {}".format(step , exc) + db_nsr["operational-status"] = "failed" + self.update_nsr_db(nsr_id, db_nsr) async def test(self, param=None): self.logger.debug("Starting/Ending test task: {}".format(param)) @@ -352,6 +465,7 @@ class Lcm: elif command.startswith("#"): continue elif command == "echo": + # just for test print(params) elif command == "test": asyncio.Task(self.test(params), loop=self.loop) @@ -360,7 +474,7 @@ class Lcm: elif command == "create": nsr_id = params.strip() self.logger.debug("Deploying NS {}".format(nsr_id)) - task = asyncio.ensure_future(self.create_ns(nsr_id)) + task = asyncio.ensure_future(self.create_ns(nsr_id, order_id)) if nsr_id not in self.lcm_tasks: self.lcm_tasks[nsr_id] = {} self.lcm_tasks[nsr_id][order_id] = {"create_ns": task} @@ -368,18 +482,24 @@ class Lcm: nsr_id = params.strip() self.logger.debug("Deleting NS {}".format(nsr_id)) self.cancel_tasks(nsr_id) - task = asyncio.ensure_future(self.delete_ns(nsr_id)) + task = asyncio.ensure_future(self.delete_ns(nsr_id, order_id)) if nsr_id not in self.lcm_tasks: self.lcm_tasks[nsr_id] = {} self.lcm_tasks[nsr_id][order_id] = {"delete_ns": task} elif command == "show": + # just for test nsr_id = params.strip() - nsr_lcm = self.db.get_one("nsr_lcm", {"id": nsr_id}) - print("nsr_lcm", nsr_lcm) - print("self.lcm_tasks", self.lcm_tasks.get(nsr_id)) + try: + db_nsr = self.db.get_one("nsrs", {"_id": nsr_id}) + print("nsr:\n _id={}\n operational-status: {}\n config-status: {}\n detailed-status: " + "{}\n deploy: {}\n tasks: {}".format( + nsr_id, db_nsr["operational-status"], + db_nsr["config-status"], db_nsr["detailed-status"], + db_nsr["_admin"]["deploy"], self.lcm_tasks.get(nsr_id))) + except Exception as e: + print("nsr {} not found: {}".format(nsr_id, e)) else: - self.logger.debug("unknown command '{}'".format(command)) - print("Usage:\n echo: <>\n create: \n delete: \n show: ") + self.logger.critical("unknown command '{}'".format(command)) self.logger.debug("kafka task Exit") @@ -425,41 +545,4 @@ if __name__ == '__main__': config_file = "lcm.cfg" lcm = Lcm(config_file) - # # FOR TEST - # RO_VIM = "OST2_MRT" - # - # #FILL DATABASE - # with open("/home/atierno/OSM/osm/devops/descriptor-packages/vnfd/ping_vnf/src/ping_vnfd.yaml") as f: - # vnfd = yaml.load(f) - # vnfd_clean, _ = ROclient.remove_envelop("vnfd", vnfd) - # vnfd_clean["_admin"] = {"storage": "/home/atierno/OSM/osm/devops/descriptor-packages/vnfd/ping_vnf"} - # lcm.db.create("vnfd", vnfd_clean) - # with open("/home/atierno/OSM/osm/devops/descriptor-packages/vnfd/pong_vnf/src/pong_vnfd.yaml") as f: - # vnfd = yaml.load(f) - # vnfd_clean, _ = ROclient.remove_envelop("vnfd", vnfd) - # vnfd_clean["_admin"] = {"storage": "/home/atierno/OSM/osm/devops/descriptor-packages/vnfd/pong_vnf"} - # lcm.db.create("vnfd", vnfd_clean) - # with open("/home/atierno/OSM/osm/devops/descriptor-packages/nsd/ping_pong_ns/src/ping_pong_nsd.yaml") as f: - # nsd = yaml.load(f) - # nsd_clean, _ = ROclient.remove_envelop("nsd", nsd) - # nsd_clean["_admin"] = {"storage": "/home/atierno/OSM/osm/devops/descriptor-packages/nsd/ping_pong_ns"} - # lcm.db.create("nsd", nsd_clean) - # - # ns_request = { - # "id": "ns1", - # "nsr_id": "ns1", - # "name": "pingpongOne", - # "vim": RO_VIM, - # "nsd_id": nsd_clean["id"], # nsd_ping_pong - # } - # lcm.db.create("ns_request", ns_request) - # ns_request = { - # "id": "ns2", - # "nsr_id": "ns2", - # "name": "pingpongTwo", - # "vim": RO_VIM, - # "nsd_id": nsd_clean["id"], # nsd_ping_pong - # } - # lcm.db.create("ns_request", ns_request) - lcm.start() diff --git a/lcm/osm_lcm/vca.py b/lcm/osm_lcm/vca.py index b2b26633..d5820969 100644 --- a/lcm/osm_lcm/vca.py +++ b/lcm/osm_lcm/vca.py @@ -17,7 +17,7 @@ class VCAMonitor(ModelObserver): """React to changes in the Juju model.""" status = None db_nsr = self.context['db_nsr'] - vnf_id = self.context['vnf_id'] + vnf_index = self.context['vnf_index'] nsr_lcm = db_nsr["_admin"]["deploy"] nsr_id = nsr_lcm["id"] @@ -39,15 +39,15 @@ class VCAMonitor(ModelObserver): status = "DELETING" if status: - nsr_lcm["VCA"][vnf_id]['operational-status'] = status + nsr_lcm["VCA"][vnf_index]['operational-status'] = status # TODO: Clean this up, and make it work with deletes (if we need # TODO: to update the database post-delete) # Figure out if we're finished configuring count = len(nsr_lcm["VCA"]) active = 0 - for vnf_id in nsr_lcm["VCA"]: - if nsr_lcm["VCA"][vnf_id]['operational-status'] == "ACTIVE": + for vnf_index in nsr_lcm["VCA"]: + if nsr_lcm["VCA"][vnf_index]['operational-status'] == "ACTIVE": active += 1 if active == count: db_nsr["config-status"] = "done" @@ -78,7 +78,6 @@ class VCAMonitor(ModelObserver): def GetJujuApi(config): # Quiet logging from the websocket library. If you want to see # everything sent over the wire, set this to DEBUG. - logging.basicConfig(level=logging.DEBUG) ws_logger = logging.getLogger('websockets.protocol') ws_logger.setLevel(logging.INFO) @@ -121,7 +120,7 @@ def get_initial_config(initial_config_primitive, mgmt_ip): async def DeployApplication(vcaconfig, db, db_nsr, vnfd, - vnfd_index, charm_path): + vnf_index, charm_path): """ Deploy a charm. @@ -136,7 +135,7 @@ async def DeployApplication(vcaconfig, db, db_nsr, vnfd, DeployApplication(...) """ nsr_lcm = db_nsr["_admin"]["deploy"] - nsr_id = nsr_lcm["id"] + nsr_id = db_nsr["_id"] vnf_id = vnfd['id'] if "proxy" in vnfd["vnf-configuration"]["juju"]: @@ -147,8 +146,8 @@ async def DeployApplication(vcaconfig, db, db_nsr, vnfd, application = get_vnf_unique_name( db_nsr["name"].lower().strip(), - vnfd['id'], - vnfd_index, + vnf_id, + vnf_index, ) api = GetJujuApi(vcaconfig) @@ -159,16 +158,16 @@ async def DeployApplication(vcaconfig, db, db_nsr, vnfd, # Set the INIT state; further operational status updates # will be made by the VCAMonitor - nsr_lcm["VCA"][vnf_id] = {} - nsr_lcm["VCA"][vnf_id]['operational-status'] = 'INIT' - nsr_lcm["VCA"][vnf_id]['application'] = application + nsr_lcm["VCA"][vnf_index] = {} + nsr_lcm["VCA"][vnf_index]['operational-status'] = 'INIT' + nsr_lcm["VCA"][vnf_index]['application'] = application db.replace("nsrs", nsr_id, db_nsr) model = await api.get_model() context = { 'application': application, - 'vnf_id': vnf_id, + 'vnf_index': vnf_index, 'db_nsr': db_nsr, 'db': db, } @@ -186,7 +185,7 @@ async def DeployApplication(vcaconfig, db, db_nsr, vnfd, vnfd["vnf-configuration"].get( "initial-config-primitive" ), - nsr_lcm['nsr_ip'][vnfd_index] + nsr_lcm['nsr_ip'][vnf_index] ) await api.apply_config(cfg, application) @@ -194,7 +193,7 @@ async def DeployApplication(vcaconfig, db, db_nsr, vnfd, await api.logout() -async def RemoveApplication(vcaconfig, db, db_nsr, vnfd, vnfd_index): +async def RemoveApplication(vcaconfig, db, db_nsr, vnf_index): """ Remove an application from the Juju Controller @@ -208,9 +207,9 @@ async def RemoveApplication(vcaconfig, db, db_nsr, vnfd, vnfd_index): RemoveApplication(loop, "ping_vnf") RemoveApplication(loop, "pong_vnf") """ + nsr_id = db_nsr["_id"] nsr_lcm = db_nsr["_admin"]["deploy"] - vnf_id = vnfd['id'] - application = nsr_lcm["VCA"][vnf_id]['application'] + application = nsr_lcm["VCA"][vnf_index]['application'] api = GetJujuApi(vcaconfig) @@ -219,7 +218,7 @@ async def RemoveApplication(vcaconfig, db, db_nsr, vnfd, vnfd_index): model = await api.get_model() context = { 'application': application, - 'vnf_id': vnf_id, + 'vnf_index': vnf_index, 'db_nsr': db_nsr, 'db': db, } @@ -230,4 +229,6 @@ async def RemoveApplication(vcaconfig, db, db_nsr, vnfd, vnfd_index): print("VCA: Removing application {}".format(application)) await api.remove_application(application) + nsr_lcm["VCA"][vnf_index]['application'] = None + db.replace("nsrs", nsr_id, db_nsr) await api.logout()